Oct 12 19:58:00 bcik volumio[2319]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Oct 12 19:58:00 bcik volumio[2319]: info: Initializing connection to go-librespot Websocket Oct 12 19:58:00 bcik volumio[2319]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 19:58:01 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 63. Oct 12 19:58:01 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:58:01 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:58:01 bcik go-librespot[2583]: go-librespot daemon starting... Oct 12 19:58:01 bcik go-librespot[2584]: time="2026-10-12T19:58:01+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 19:58:01 bcik go-librespot[2584]: time="2026-10-12T19:58:01+02:00" level=debug msg="app state loaded" Oct 12 19:58:01 bcik go-librespot[2584]: time="2026-10-12T19:58:01+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 19:58:01 bcik go-librespot[2584]: time="2026-10-12T19:58:01+02: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]" Oct 12 19:58:01 bcik go-librespot[2584]: time="2026-10-12T19:58:01+02: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]" Oct 12 19:58:01 bcik go-librespot[2584]: time="2026-10-12T19:58:01+02: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]" Oct 12 19:58:01 bcik go-librespot[2584]: time="2026-10-12T19:58:01+02:00" level=info msg="zeroconf server listening on port 37747" Oct 12 19:58:01 bcik go-librespot[2584]: time="2026-10-12T19:58:01+02:00" level=debug msg="obtained new client token: AAHxJF5zRHtwWu1kzMuduRY7m6RBmuOHDHBG+oQ20qq+UYyuZqIDkjFSFtQ+JneI7F6h6wVYqYapNMJW1c0/YZOLlc2RwlSW6x4Xgg6203P/TffbEgNEokACLAz/K5eB4RQguSgDeMikUFU1Ee5LEmnnLhpHlquI354b56YJTDtwCV2r3RM6kkBDetUaMQHFrTc7XhZfiYaOM7EmJ13QodQiqs5KIFpowiFGiKy0y6259AmruRi8VX8=" Oct 12 19:58:02 bcik go-librespot[2584]: time="2026-10-12T19:58:02+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 19:58:02 bcik go-librespot[2584]: time="2026-10-12T19:58:02+02:00" level=debug msg="completed keyexchange" Oct 12 19:58:02 bcik go-librespot[2584]: time="2026-10-12T19:58:02+02:00" level=debug msg="completed challenge" Oct 12 19:58:02 bcik go-librespot[2584]: time="2026-10-12T19:58:02+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 19:58:02 bcik go-librespot[2584]: time="2026-10-12T19:58:02+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 19:58:02 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 19:58:02 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 19:58:03 bcik volumio[2319]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Oct 12 19:58:03 bcik volumio[2319]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Oct 12 19:58:03 bcik volumio[2319]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Oct 12 19:58:03 bcik volumio[2319]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Oct 12 19:58:03 bcik volumio[2319]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Oct 12 19:58:03 bcik volumio[2319]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Oct 12 19:58:03 bcik volumio[2319]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Oct 12 19:58:03 bcik volumio[2319]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Oct 12 19:58:03 bcik volumio[2319]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Oct 12 19:58:03 bcik volumio[2319]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Oct 12 19:58:03 bcik volumio[2319]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Oct 12 19:58:03 bcik volumio[2319]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Oct 12 19:58:03 bcik volumio[2319]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Oct 12 19:58:03 bcik volumio[2319]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Oct 12 19:58:03 bcik volumio[2319]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Oct 12 19:58:03 bcik volumio[2319]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Oct 12 19:58:03 bcik volumio[2319]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Oct 12 19:58:03 bcik volumio[2319]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Oct 12 19:58:03 bcik volumio[2319]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Oct 12 19:58:03 bcik volumio[2319]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Oct 12 19:58:03 bcik volumio[2319]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Oct 12 19:58:03 bcik volumio[2319]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Oct 12 19:58:03 bcik volumio[2319]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Oct 12 19:58:03 bcik volumio[2319]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Oct 12 19:58:03 bcik volumio[2319]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Oct 12 19:58:03 bcik volumio[2319]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Oct 12 19:58:03 bcik volumio[2319]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Oct 12 19:58:03 bcik volumio[2319]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Oct 12 19:58:03 bcik volumio[2319]: info: Adding plugin bluetooth to MyMusic Plugins Oct 12 19:58:03 bcik volumio[2319]: info: Adding plugin multiroom to MyMusic Plugins Oct 12 19:58:03 bcik volumio[2319]: info: Adding plugin metavolumio to MyMusic Plugins Oct 12 19:58:03 bcik volumio[2319]: info: Adding plugin cd_controller to MyMusic Plugins Oct 12 19:58:03 bcik volumio[2319]: info: Adding plugin qobuzconnect to MyMusic Plugins Oct 12 19:58:03 bcik volumio[2319]: info: Adding plugin smart_inputs to MyMusic Plugins Oct 12 19:58:03 bcik volumio[2319]: info: Adding plugin tidalconnect to MyMusic Plugins Oct 12 19:58:03 bcik volumio[2319]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Oct 12 19:58:03 bcik volumio[2319]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Oct 12 19:58:03 bcik volumio[2319]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Oct 12 19:58:03 bcik volumio[2319]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 19:58:03 bcik volumio[2319]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 19:58:03 bcik volumio[2319]: info: Starting MyVolumio Remote Streaming Endpoints Oct 12 19:58:03 bcik volumio[2319]: info: MyVolumio login type: Token Oct 12 19:58:03 bcik volumio[2319]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Oct 12 19:58:03 bcik volumio[2319]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Oct 12 19:58:03 bcik volumio[2319]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Oct 12 19:58:03 bcik volumio[2319]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Oct 12 19:58:03 bcik volumio[2319]: info: Streaming services startup Oct 12 19:58:03 bcik volumio[2319]: info: Starting Streaming Daemon Oct 12 19:58:03 bcik volumio[2319]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Oct 12 19:58:03 bcik sudo[2609]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 12 19:58:03 bcik sudo[2609]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 19:58:03 bcik sudo[2609]: pam_unix(sudo:session): session closed for user root Oct 12 19:58:03 bcik sudo[2616]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 12 19:58:03 bcik sudo[2616]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 19:58:03 bcik volumio[2319]: error: Cannot start Volumio Streaming Daemon Oct 12 19:58:03 bcik volumio[2319]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 12 19:58:03 bcik volumio[2319]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 12 19:58:03 bcik sudo[2618]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 12 19:58:03 bcik sudo[2618]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 19:58:03 bcik sudo[2618]: pam_unix(sudo:session): session closed for user root Oct 12 19:58:03 bcik sudo[2616]: pam_unix(sudo:session): session closed for user root Oct 12 19:58:03 bcik sudo[2622]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Oct 12 19:58:03 bcik sudo[2622]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 19:58:03 bcik sudo[2622]: pam_unix(sudo:session): session closed for user root Oct 12 19:58:03 bcik volumio[2319]: info: Upmpdcli Daemon Started Oct 12 19:58:03 bcik volumio[2319]: info: Initializing connection to go-librespot Websocket Oct 12 19:58:03 bcik volumio[2319]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 19:58:04 bcik volumio[2319]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Oct 12 19:58:04 bcik volumio[2319]: info: MyVolumio token set successfully Oct 12 19:58:04 bcik volumio[2319]: info: MYVOLUMIO: Adding device Oct 12 19:58:04 bcik volumio[2319]: info: MYVOLUMIO: Evaluating Server Oct 12 19:58:04 bcik volumio[2319]: info: MyVolumio status changed Oct 12 19:58:04 bcik volumio[2319]: info: Streaming services startup Oct 12 19:58:04 bcik volumio[2319]: info: Starting Streaming Daemon Oct 12 19:58:04 bcik volumio[2319]: info: Removing browser output: myVolumio user plan is not superstar Oct 12 19:58:04 bcik volumio[2319]: info: Removing audio output: Oct 12 19:58:04 bcik volumio[2319]: info: Stoppping Tunnel 1 Oct 12 19:58:04 bcik sudo[2645]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 12 19:58:04 bcik sudo[2645]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 19:58:04 bcik sudo[2647]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Oct 12 19:58:04 bcik sudo[2647]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 19:58:04 bcik 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. Oct 12 19:58:04 bcik 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. Oct 12 19:58:04 bcik sudo[2645]: pam_unix(sudo:session): session closed for user root Oct 12 19:58:04 bcik 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. Oct 12 19:58:04 bcik volumio[2319]: error: Cannot start Volumio Streaming Daemon Oct 12 19:58:04 bcik volumio[2319]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 12 19:58:04 bcik volumio[2319]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 12 19:58:04 bcik 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. Oct 12 19:58:04 bcik 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. Oct 12 19:58:04 bcik 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. Oct 12 19:58:04 bcik 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. Oct 12 19:58:04 bcik 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. Oct 12 19:58:04 bcik sudo[2647]: pam_unix(sudo:session): session closed for user root Oct 12 19:58:04 bcik volumio[2319]: info: Remote SSH Stopped Oct 12 19:58:05 bcik volumio[2319]: info: Setting Geolocation for MyVolumio to eu6 Oct 12 19:58:05 bcik volumio[2319]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 19:58:05 bcik volumio[2319]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 19:58:05 bcik volumio[2319]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 19:58:05 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 64. Oct 12 19:58:05 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:58:05 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:58:05 bcik go-librespot[2650]: go-librespot daemon starting... Oct 12 19:58:05 bcik go-librespot[2651]: time="2026-10-12T19:58:05+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 19:58:05 bcik go-librespot[2651]: time="2026-10-12T19:58:05+02:00" level=debug msg="app state loaded" Oct 12 19:58:05 bcik go-librespot[2651]: time="2026-10-12T19:58:05+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 19:58:05 bcik go-librespot[2651]: time="2026-10-12T19:58:05+02: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]" Oct 12 19:58:05 bcik go-librespot[2651]: time="2026-10-12T19:58:05+02: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]" Oct 12 19:58:05 bcik go-librespot[2651]: time="2026-10-12T19:58:05+02: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]" Oct 12 19:58:05 bcik volumio[2319]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Oct 12 19:58:05 bcik go-librespot[2651]: time="2026-10-12T19:58:05+02:00" level=info msg="zeroconf server listening on port 33699" Oct 12 19:58:05 bcik go-librespot[2651]: time="2026-10-12T19:58:05+02:00" level=debug msg="obtained new client token: AAEJOSughvyfgktQrJxs06me1QSk00ftvZdi5jZNBegDj0VCsh2u1YhRVz7paKZWYdftOZWc4KTLg+LEtrzxUH/58jTAMWUdMdMpdJLPVXd+dojycoFaHDKhiH1Qz7frmqtDE30mTyl0f7UVm+18lA0OGtNs9xK1Uc83Va1SkT/4+b/dB5xKRI7MT3FRGvo2hX9ar+NLQybIwRIiSraXJbUeOaSxc2miiIz7/I7tTS7+8uORQa3HAAg=" Oct 12 19:58:05 bcik go-librespot[2651]: time="2026-10-12T19:58:05+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 19:58:05 bcik go-librespot[2651]: time="2026-10-12T19:58:05+02:00" level=debug msg="completed keyexchange" Oct 12 19:58:05 bcik go-librespot[2651]: time="2026-10-12T19:58:05+02:00" level=debug msg="completed challenge" Oct 12 19:58:05 bcik go-librespot[2651]: time="2026-10-12T19:58:05+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 19:58:05 bcik go-librespot[2651]: time="2026-10-12T19:58:05+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 19:58:05 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 19:58:05 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 19:58:06 bcik volumio[2319]: info: Updating MyVolumio device info Oct 12 19:58:06 bcik volumio[2319]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 19:58:06 bcik volumio[2319]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 19:58:06 bcik volumio[2319]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 19:58:06 bcik volumio[2319]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Oct 12 19:58:06 bcik volumio[2319]: info: Initializing connection to go-librespot Websocket Oct 12 19:58:06 bcik volumio[2319]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 19:58:08 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 65. Oct 12 19:58:08 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:58:08 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:58:08 bcik go-librespot[2660]: go-librespot daemon starting... Oct 12 19:58:08 bcik go-librespot[2661]: time="2026-10-12T19:58:08+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 19:58:08 bcik go-librespot[2661]: time="2026-10-12T19:58:08+02:00" level=debug msg="app state loaded" Oct 12 19:58:08 bcik go-librespot[2661]: time="2026-10-12T19:58:08+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 19:58:08 bcik go-librespot[2661]: time="2026-10-12T19:58:08+02: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]" Oct 12 19:58:08 bcik go-librespot[2661]: time="2026-10-12T19:58:08+02: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]" Oct 12 19:58:08 bcik go-librespot[2661]: time="2026-10-12T19:58:08+02: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]" Oct 12 19:58:08 bcik go-librespot[2661]: time="2026-10-12T19:58:08+02:00" level=info msg="zeroconf server listening on port 43869" Oct 12 19:58:08 bcik go-librespot[2661]: time="2026-10-12T19:58:08+02:00" level=debug msg="obtained new client token: AAH5WVZouHZsLGBXG1NKc20A2fy0WeEvmhW+FoQa0Y86JKFYK6rBlqpe0DIWESZz9bjVLSthbLmvVEL/O6sge11NC0Yre8ULQFghx6rYxraAI+/BZJLnFK4s3D6PxxRVcdD2B1gh2lzQYi1DVBXyEw1e81CBFI2eL0NmSCUvbeyYLE5r9jV4JzJohp9RSi4bKTLm4Lr7Z8EGcggDLDL/L6oA38THxzQxvvEGoT+V6gjb3JO+hpsJrPs=" Oct 12 19:58:09 bcik go-librespot[2661]: time="2026-10-12T19:58:09+02: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" Oct 12 19:58:09 bcik go-librespot[2661]: time="2026-10-12T19:58:09+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Oct 12 19:58:09 bcik go-librespot[2661]: time="2026-10-12T19:58:09+02:00" level=debug msg="completed keyexchange" Oct 12 19:58:09 bcik go-librespot[2661]: time="2026-10-12T19:58:09+02:00" level=debug msg="completed challenge" Oct 12 19:58:09 bcik go-librespot[2661]: time="2026-10-12T19:58:09+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 19:58:09 bcik go-librespot[2661]: time="2026-10-12T19:58:09+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 19:58:09 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 19:58:09 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 19:58:09 bcik volumio[2319]: info: MYVOLUMIO: Adding device Oct 12 19:58:09 bcik volumio[2319]: info: MYVOLUMIO: Evaluating Server Oct 12 19:58:09 bcik volumio[2319]: info: Initializing connection to go-librespot Websocket Oct 12 19:58:09 bcik volumio[2319]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 19:58:09 bcik volumio[2319]: info: Setting Geolocation for MyVolumio to eu6 Oct 12 19:58:09 bcik volumio[2319]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 19:58:09 bcik volumio[2319]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 19:58:09 bcik volumio[2319]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 19:58:10 bcik volumio[2319]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Oct 12 19:58:10 bcik volumio[2319]: info: Updating MyVolumio device info Oct 12 19:58:10 bcik volumio[2319]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 19:58:10 bcik volumio[2319]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 19:58:10 bcik volumio[2319]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 19:58:11 bcik volumio[2319]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Oct 12 19:58:12 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 66. Oct 12 19:58:12 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:58:12 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:58:12 bcik go-librespot[2688]: go-librespot daemon starting... Oct 12 19:58:12 bcik go-librespot[2689]: time="2026-10-12T19:58:12+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 19:58:12 bcik go-librespot[2689]: time="2026-10-12T19:58:12+02:00" level=debug msg="app state loaded" Oct 12 19:58:12 bcik go-librespot[2689]: time="2026-10-12T19:58:12+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 19:58:12 bcik go-librespot[2689]: time="2026-10-12T19:58:12+02: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]" Oct 12 19:58:12 bcik go-librespot[2689]: time="2026-10-12T19:58:12+02: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]" Oct 12 19:58:12 bcik go-librespot[2689]: time="2026-10-12T19:58:12+02: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]" Oct 12 19:58:12 bcik go-librespot[2689]: time="2026-10-12T19:58:12+02:00" level=info msg="zeroconf server listening on port 40827" Oct 12 19:58:12 bcik go-librespot[2689]: time="2026-10-12T19:58:12+02:00" level=debug msg="obtained new client token: AAFf700kIGRFDDawE7ftNEfumh1EfEXdqvVO/AMX+sMLSbXpXpCmysCpBRmhfI5KIxTPfW0++BRTMjRftVl4nfdP659z2R1YflNfGvfYwZ/vNdQTdAJmJHrnmuxUflnqxM2UPSvKpOJeoW94DYjbKNXGN6VzPmIaafhPTxPpvffJRe4hYxj69wV6wMfIZPmW1kHUDQTUSi2UH1Hz5J200y1caKGDmAM7ChhItuH+1UBvy20nj3Z6qH0=" Oct 12 19:58:12 bcik go-librespot[2689]: time="2026-10-12T19:58:12+02: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" Oct 12 19:58:12 bcik go-librespot[2689]: time="2026-10-12T19:58:12+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Oct 12 19:58:12 bcik go-librespot[2689]: time="2026-10-12T19:58:12+02:00" level=debug msg="completed keyexchange" Oct 12 19:58:12 bcik go-librespot[2689]: time="2026-10-12T19:58:12+02:00" level=debug msg="completed challenge" Oct 12 19:58:12 bcik go-librespot[2689]: time="2026-10-12T19:58:12+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 19:58:12 bcik go-librespot[2689]: time="2026-10-12T19:58:12+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 19:58:12 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 19:58:12 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 19:58:12 bcik volumio[2319]: info: Initializing connection to go-librespot Websocket Oct 12 19:58:12 bcik volumio[2319]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 19:58:15 bcik volumio[2319]: info: Initializing connection to go-librespot Websocket Oct 12 19:58:15 bcik volumio[2319]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 19:58:15 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 67. Oct 12 19:58:15 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:58:15 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:58:15 bcik go-librespot[2712]: go-librespot daemon starting... Oct 12 19:58:15 bcik go-librespot[2713]: time="2026-10-12T19:58:15+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 19:58:15 bcik go-librespot[2713]: time="2026-10-12T19:58:15+02:00" level=debug msg="app state loaded" Oct 12 19:58:15 bcik go-librespot[2713]: time="2026-10-12T19:58:15+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 19:58:15 bcik go-librespot[2713]: time="2026-10-12T19:58:15+02: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]" Oct 12 19:58:15 bcik go-librespot[2713]: time="2026-10-12T19:58:15+02: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]" Oct 12 19:58:15 bcik go-librespot[2713]: time="2026-10-12T19:58:15+02: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]" Oct 12 19:58:15 bcik go-librespot[2713]: time="2026-10-12T19:58:15+02:00" level=info msg="zeroconf server listening on port 46829" Oct 12 19:58:15 bcik go-librespot[2713]: time="2026-10-12T19:58:15+02:00" level=debug msg="obtained new client token: AAFCwPo84eKcZ1TCoeb9i9jNJVB0XqEwAStLkVpBBtm1PFc36i/Gd97Mam2IXcUKf5Elz0dxo/wJmFMIlOtYw8CPRa6ElI1Ho9zjIpN/aAJiZsMvh2Atx7IX+8qG6nx7mNOA0wC0ffqsHmp3eb+JZ8Qy+p9AGkp/5dl0MCknjXghhFdhXirezVXiJe14yPKjImEytrWtQ+o//ETBhOo26qD1tC6UNR7RHgE2UOSvwIRKKsz0x/dd5Io=" Oct 12 19:58:16 bcik go-librespot[2713]: time="2026-10-12T19:58:16+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 19:58:16 bcik go-librespot[2713]: time="2026-10-12T19:58:16+02:00" level=debug msg="completed keyexchange" Oct 12 19:58:16 bcik go-librespot[2713]: time="2026-10-12T19:58:16+02:00" level=debug msg="completed challenge" Oct 12 19:58:16 bcik go-librespot[2713]: time="2026-10-12T19:58:16+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 19:58:16 bcik go-librespot[2713]: time="2026-10-12T19:58:16+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 19:58:16 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 19:58:16 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 19:58:18 bcik volumio[2319]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 12 19:58:18 bcik volumio[2319]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Oct 12 19:58:18 bcik volumio[2319]: info: CoreCommandRouter::volumioGetState Oct 12 19:58:18 bcik volumio[2319]: info: CorePlayQueue::getTrack 0 Oct 12 19:58:18 bcik volumio[2319]: info: Initializing connection to go-librespot Websocket Oct 12 19:58:18 bcik volumio[2319]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 19:58:19 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 68. Oct 12 19:58:19 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:58:19 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:58:19 bcik go-librespot[2722]: go-librespot daemon starting... Oct 12 19:58:19 bcik go-librespot[2723]: time="2026-10-12T19:58:19+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 19:58:19 bcik go-librespot[2723]: time="2026-10-12T19:58:19+02:00" level=debug msg="app state loaded" Oct 12 19:58:19 bcik go-librespot[2723]: time="2026-10-12T19:58:19+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 19:58:19 bcik go-librespot[2723]: time="2026-10-12T19:58:19+02: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]" Oct 12 19:58:19 bcik go-librespot[2723]: time="2026-10-12T19:58:19+02: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]" Oct 12 19:58:19 bcik go-librespot[2723]: time="2026-10-12T19:58:19+02: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]" Oct 12 19:58:19 bcik go-librespot[2723]: time="2026-10-12T19:58:19+02:00" level=info msg="zeroconf server listening on port 37995" Oct 12 19:58:19 bcik go-librespot[2723]: time="2026-10-12T19:58:19+02:00" level=debug msg="obtained new client token: AAFQbgSItw7FHwgJ/voUZQdU/lzzMdBatxQs91G180VC6TvjUspEBTdeS5UiTE6COMZ8OcLyo6V9UeZ/2yVA/YnJXaolrgO2/sjBGO/0q3/uGnos1FzAfszvNrTr8RmEBDR1us6uG9kPtvNmxjD9XxVZWqOEkGFn4MBVnsaIecV/pUaY3XeSHUTUnvT4gaSMpvQEerZ0hYo/O4z5ZUOe/lcWCBuvvVjkq6fSnWEfBI+uAMQHltW6f3Q=" Oct 12 19:58:19 bcik go-librespot[2723]: time="2026-10-12T19:58:19+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 19:58:19 bcik go-librespot[2723]: time="2026-10-12T19:58:19+02:00" level=debug msg="completed keyexchange" Oct 12 19:58:19 bcik go-librespot[2723]: time="2026-10-12T19:58:19+02:00" level=debug msg="completed challenge" Oct 12 19:58:19 bcik go-librespot[2723]: time="2026-10-12T19:58:19+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 19:58:19 bcik go-librespot[2723]: time="2026-10-12T19:58:19+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 19:58:19 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 19:58:19 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 19:58:21 bcik volumio[2319]: info: Initializing connection to go-librespot Websocket Oct 12 19:58:21 bcik volumio[2319]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 19:58:22 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 69. Oct 12 19:58:22 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:58:22 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:58:22 bcik go-librespot[2732]: go-librespot daemon starting... Oct 12 19:58:22 bcik go-librespot[2733]: time="2026-10-12T19:58:22+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 19:58:22 bcik go-librespot[2733]: time="2026-10-12T19:58:22+02:00" level=debug msg="app state loaded" Oct 12 19:58:22 bcik go-librespot[2733]: time="2026-10-12T19:58:22+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 19:58:22 bcik go-librespot[2733]: time="2026-10-12T19:58:22+02: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]" Oct 12 19:58:22 bcik go-librespot[2733]: time="2026-10-12T19:58:22+02: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]" Oct 12 19:58:22 bcik go-librespot[2733]: time="2026-10-12T19:58:22+02: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]" Oct 12 19:58:22 bcik go-librespot[2733]: time="2026-10-12T19:58:22+02:00" level=info msg="zeroconf server listening on port 35237" Oct 12 19:58:22 bcik go-librespot[2733]: time="2026-10-12T19:58:22+02:00" level=debug msg="obtained new client token: AAFt1KiSYuIOcJ/4dao9BdajMB7TmgYHFVKondrFcIwW2fHImcs1OLyrs/TLmZTOXz+FFcNT4DjDUD5ZQCNUisE2BwKEN0pkZJ4TxP4A4vSh4dMKhav5hi12x03FjFRMFcpOOUYUhwwJFCYsIkKnS5F+9zoijzmYQu72srVXKhV0r4rmSOi2kCf9knh0RHDnh+4/4hADKllywgTyO/q381lunIrIOs/2kRcWKH3/b/+wh28oj7K/rdo=" Oct 12 19:58:23 bcik go-librespot[2733]: time="2026-10-12T19:58:23+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 19:58:23 bcik go-librespot[2733]: time="2026-10-12T19:58:23+02:00" level=debug msg="completed keyexchange" Oct 12 19:58:23 bcik go-librespot[2733]: time="2026-10-12T19:58:23+02:00" level=debug msg="completed challenge" Oct 12 19:58:23 bcik go-librespot[2733]: time="2026-10-12T19:58:23+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 19:58:23 bcik go-librespot[2733]: time="2026-10-12T19:58:23+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 19:58:23 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 19:58:23 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 19:58:23 bcik volumio[2319]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:58:23 bcik volumio[2319]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:58:23 bcik volumio[2319]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Oct 12 19:58:23 bcik volumio[2319]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Oct 12 19:58:23 bcik volumio[2319]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Oct 12 19:58:23 bcik volumio[2319]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Oct 12 19:58:23 bcik volumio[2319]: info: CoreCommandRouter::volumioGetBrowseSources Oct 12 19:58:23 bcik volumio[2319]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 12 19:58:23 bcik volumio[2319]: error: MyVolumio Plugin failed to authenticate in a timely fashion Oct 12 19:58:23 bcik volumio[2319]: info: Completed starting MyVolumio Plugin Oct 12 19:58:23 bcik volumio[2319]: [Metrics] CommandRouter: 30s 623.63ms Oct 12 19:58:23 bcik volumio[2319]: info: CoreCommandRouter::volumiosetStartupVolume Oct 12 19:58:23 bcik volumio[2319]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:58:23 bcik volumio[2319]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 19:58:23 bcik volumio[2319]: info: CoreCommandRouter::Close All Modals sent Oct 12 19:58:23 bcik volumio[2319]: info: CoreCommandRouter::Close All Modals sent Oct 12 19:58:24 bcik volumio[2319]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 12 19:58:24 bcik volumio[2319]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 19:58:24 bcik volumio[2319]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 12 19:58:24 bcik volumio[2319]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Oct 12 19:58:24 bcik volumio[2319]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 12 19:58:24 bcik volumio[2319]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Oct 12 19:58:24 bcik volumio-remote-updater[9031]: Test mode disabled Oct 12 19:58:24 bcik volumio-remote-updater[9031]: Alpha mode disabled Oct 12 19:58:24 bcik volumio-remote-updater[9031]: Alpha legacy test mode disabled Oct 12 19:58:24 bcik volumio[2319]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Oct 12 19:58:24 bcik volumio[2319]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Oct 12 19:58:24 bcik volumio[2319]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Oct 12 19:58:24 bcik volumio[2319]: info: Initializing connection to go-librespot Websocket Oct 12 19:58:24 bcik volumio[2319]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 19:58:26 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 70. Oct 12 19:58:26 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:58:26 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:58:26 bcik go-librespot[2763]: go-librespot daemon starting... Oct 12 19:58:26 bcik go-librespot[2764]: time="2026-10-12T19:58:26+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 19:58:26 bcik go-librespot[2764]: time="2026-10-12T19:58:26+02:00" level=debug msg="app state loaded" Oct 12 19:58:26 bcik go-librespot[2764]: time="2026-10-12T19:58:26+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 19:58:26 bcik go-librespot[2764]: time="2026-10-12T19:58:26+02: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]" Oct 12 19:58:26 bcik go-librespot[2764]: time="2026-10-12T19:58:26+02: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]" Oct 12 19:58:26 bcik go-librespot[2764]: time="2026-10-12T19:58:26+02: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]" Oct 12 19:58:26 bcik go-librespot[2764]: time="2026-10-12T19:58:26+02:00" level=info msg="zeroconf server listening on port 35995" Oct 12 19:58:26 bcik go-librespot[2764]: time="2026-10-12T19:58:26+02:00" level=debug msg="obtained new client token: AAHuDusOf7UwLEl84R9iXLF7Mlsc5LefK+M+nPWj3ZsBzdasTz4dklak7E3y4Ue6DjW+hRBy8P5IcPpJhaCiTw1Ut2BwcxpyBClFfgJmH0Vvt4FiCQ4xEzPSytVFy8XmRnMaiD9TXx3eKb3ArCvaAMqOU/hYcuVsUED9Jfd9MxtfA55bNTzwnHEEcRSb7NoPG4Rv399vWBcaGYhA8X0ITJN67txxsNvBo8LLH8JQa/YiDxx/XgRlE5U=" Oct 12 19:58:26 bcik go-librespot[2764]: time="2026-10-12T19:58:26+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 19:58:26 bcik go-librespot[2764]: time="2026-10-12T19:58:26+02:00" level=debug msg="completed keyexchange" Oct 12 19:58:26 bcik go-librespot[2764]: time="2026-10-12T19:58:26+02:00" level=debug msg="completed challenge" Oct 12 19:58:26 bcik go-librespot[2764]: time="2026-10-12T19:58:26+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 19:58:26 bcik go-librespot[2764]: time="2026-10-12T19:58:26+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 19:58:26 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 19:58:26 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 19:58:27 bcik volumio[2319]: info: Initializing connection to go-librespot Websocket Oct 12 19:58:27 bcik volumio[2319]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 19:58:29 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 71. Oct 12 19:58:29 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:58:29 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:58:29 bcik go-librespot[2773]: go-librespot daemon starting... Oct 12 19:58:29 bcik go-librespot[2774]: time="2026-10-12T19:58:29+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 19:58:29 bcik go-librespot[2774]: time="2026-10-12T19:58:29+02:00" level=debug msg="app state loaded" Oct 12 19:58:29 bcik go-librespot[2774]: time="2026-10-12T19:58:29+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 19:58:29 bcik go-librespot[2774]: time="2026-10-12T19:58:29+02: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]" Oct 12 19:58:29 bcik go-librespot[2774]: time="2026-10-12T19:58:29+02: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]" Oct 12 19:58:29 bcik go-librespot[2774]: time="2026-10-12T19:58:29+02: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]" Oct 12 19:58:29 bcik go-librespot[2774]: time="2026-10-12T19:58:29+02:00" level=info msg="zeroconf server listening on port 36835" Oct 12 19:58:29 bcik go-librespot[2774]: time="2026-10-12T19:58:29+02:00" level=debug msg="obtained new client token: AAEdgTLttgvWs5aiL2pUPzDoDkUMoTxMFuEmMIL6A5WQOuI3F4aB/Ufc7lFjwm/4xK0E6XMYQ7ObK5QI/3s0VszQmJ0yY1s5H53GAL/7wTNO+d3p9M3+JgYVMuOVrGrWZ2t+yzvUpKnrT/AzBiFyAF57NhtZxr9kNhUugtbIaNCoHTytgkfF/pUv1imQf/2dtmaINNmAKwIs1zHMD+6Hgnk+j0foXmZLkcxIuMsqn0zxJmq8TpUVxqw=" Oct 12 19:58:30 bcik go-librespot[2774]: time="2026-10-12T19:58:30+02: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" Oct 12 19:58:30 bcik go-librespot[2774]: time="2026-10-12T19:58:30+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Oct 12 19:58:30 bcik go-librespot[2774]: time="2026-10-12T19:58:30+02:00" level=debug msg="completed keyexchange" Oct 12 19:58:30 bcik go-librespot[2774]: time="2026-10-12T19:58:30+02:00" level=debug msg="completed challenge" Oct 12 19:58:30 bcik go-librespot[2774]: time="2026-10-12T19:58:30+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 19:58:30 bcik go-librespot[2774]: time="2026-10-12T19:58:30+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 19:58:30 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 19:58:30 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 19:58:30 bcik volumio[2319]: info: BOOT COMPLETED Oct 12 19:58:30 bcik volumio[2319]: info: Initializing connection to go-librespot Websocket Oct 12 19:58:30 bcik volumio[2319]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 19:58:33 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 72. Oct 12 19:58:33 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:58:33 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:58:33 bcik go-librespot[2784]: go-librespot daemon starting... Oct 12 19:58:33 bcik go-librespot[2785]: time="2026-10-12T19:58:33+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 19:58:33 bcik go-librespot[2785]: time="2026-10-12T19:58:33+02:00" level=debug msg="app state loaded" Oct 12 19:58:33 bcik go-librespot[2785]: time="2026-10-12T19:58:33+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 19:58:33 bcik go-librespot[2785]: time="2026-10-12T19:58:33+02: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]" Oct 12 19:58:33 bcik go-librespot[2785]: time="2026-10-12T19:58:33+02: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]" Oct 12 19:58:33 bcik go-librespot[2785]: time="2026-10-12T19:58:33+02: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]" Oct 12 19:58:33 bcik go-librespot[2785]: time="2026-10-12T19:58:33+02:00" level=info msg="zeroconf server listening on port 36885" Oct 12 19:58:33 bcik go-librespot[2785]: time="2026-10-12T19:58:33+02:00" level=debug msg="obtained new client token: AAFYPjHswV2HcjsBQ0DutzADc1W9QgTprQI+yQRj6RqyyGNMZE4+q+EQ+hXOitxUsmraWGW6Nq+wMhzsJKTgcFrJMGzNxbQI4zHD1qgOZjmpR7dXcrQhuKTilqTZaKBWalEzDDN+uMfdfDP4MOOEzLyFYLYwWiN1nCJG1r/iIXVunbwG4G/KKKZV7mLw2CFR+yRSpS/5wqG8JGo8tbh1669OBJn0Dt+ZfCt1FSgih6OjX3PYdMOETYE=" Oct 12 19:58:33 bcik go-librespot[2785]: time="2026-10-12T19:58:33+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 19:58:33 bcik go-librespot[2785]: time="2026-10-12T19:58:33+02:00" level=debug msg="completed keyexchange" Oct 12 19:58:33 bcik go-librespot[2785]: time="2026-10-12T19:58:33+02:00" level=debug msg="completed challenge" Oct 12 19:58:33 bcik go-librespot[2785]: time="2026-10-12T19:58:33+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 19:58:33 bcik go-librespot[2785]: time="2026-10-12T19:58:33+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 19:58:33 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 19:58:33 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 19:58:33 bcik volumio[2319]: info: Initializing connection to go-librespot Websocket Oct 12 19:58:33 bcik volumio[2319]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 19:58:36 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 73. Oct 12 19:58:36 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:58:36 bcik volumio[2319]: info: Initializing connection to go-librespot Websocket Oct 12 19:58:36 bcik volumio[2319]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 19:58:36 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:58:36 bcik go-librespot[2808]: go-librespot daemon starting... Oct 12 19:58:36 bcik go-librespot[2809]: time="2026-10-12T19:58:36+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 19:58:36 bcik go-librespot[2809]: time="2026-10-12T19:58:36+02:00" level=debug msg="app state loaded" Oct 12 19:58:36 bcik go-librespot[2809]: time="2026-10-12T19:58:36+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 19:58:36 bcik go-librespot[2809]: time="2026-10-12T19:58:36+02: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]" Oct 12 19:58:36 bcik go-librespot[2809]: time="2026-10-12T19:58:36+02: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]" Oct 12 19:58:36 bcik go-librespot[2809]: time="2026-10-12T19:58:36+02: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]" Oct 12 19:58:36 bcik go-librespot[2809]: time="2026-10-12T19:58:36+02:00" level=info msg="zeroconf server listening on port 46749" Oct 12 19:58:37 bcik go-librespot[2809]: time="2026-10-12T19:58:37+02:00" level=debug msg="obtained new client token: AAEr7CypOwxtg73AizUk+iVS+BGt/GnAzoqBqaBbYd9/TEa9ZPyD1rvK/U7JTQXE+bUkmjmj+It40F2kKnIul6IEvM351dJoCgHWO+HZWhteEnDAGfsD/4mQ08iZ/OKNZk9neR2pQQfL8+UWJbKThEGQXspVx7aScFIUl5Omt/oeV4T7/660V6N7oJYTk6q5Mc1/9StGW8Lmsn99zF5eql+xJ2bsYi2mR8GAZc4jqmH3lh6Ho34d" Oct 12 19:58:37 bcik go-librespot[2809]: time="2026-10-12T19:58:37+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 19:58:37 bcik go-librespot[2809]: time="2026-10-12T19:58:37+02:00" level=debug msg="completed keyexchange" Oct 12 19:58:37 bcik go-librespot[2809]: time="2026-10-12T19:58:37+02:00" level=debug msg="completed challenge" Oct 12 19:58:37 bcik go-librespot[2809]: time="2026-10-12T19:58:37+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 19:58:37 bcik go-librespot[2809]: time="2026-10-12T19:58:37+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 19:58:37 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 19:58:37 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 19:58:39 bcik volumio[2319]: info: Initializing connection to go-librespot Websocket Oct 12 19:58:39 bcik volumio[2319]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 19:58:40 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 74. Oct 12 19:58:40 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:58:40 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:58:40 bcik go-librespot[2818]: go-librespot daemon starting... Oct 12 19:58:40 bcik go-librespot[2819]: time="2026-10-12T19:58:40+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 19:58:40 bcik go-librespot[2819]: time="2026-10-12T19:58:40+02:00" level=debug msg="app state loaded" Oct 12 19:58:40 bcik go-librespot[2819]: time="2026-10-12T19:58:40+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 19:58:40 bcik go-librespot[2819]: time="2026-10-12T19:58:40+02: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]" Oct 12 19:58:40 bcik go-librespot[2819]: time="2026-10-12T19:58:40+02: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]" Oct 12 19:58:40 bcik go-librespot[2819]: time="2026-10-12T19:58:40+02: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]" Oct 12 19:58:40 bcik go-librespot[2819]: time="2026-10-12T19:58:40+02:00" level=info msg="zeroconf server listening on port 38223" Oct 12 19:58:40 bcik go-librespot[2819]: time="2026-10-12T19:58:40+02:00" level=debug msg="obtained new client token: AAEzYewBDrNVy3fDoJ/k29bpUNTCMv89BZZtQgfzrdiBx6i26JOj3E80Adyj02FwkeN/mCVZlKtmtk4maQDbnzxxch/sVf+PTwVs81G5XGNMM6cRHQRD75Dx0gx1wSNan8UD3XW1ozfs0CxX2tmZ+hjvRdn2+9PyK4vyNUCM4yK6uKisoCQeMe5pRlxK6td6B7vVJG02uOIepYvllaMDHlD8irxvW5bGhLm2+xF09hi/VxK8kwuqzN8=" Oct 12 19:58:40 bcik go-librespot[2819]: time="2026-10-12T19:58:40+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 19:58:40 bcik go-librespot[2819]: time="2026-10-12T19:58:40+02:00" level=debug msg="completed keyexchange" Oct 12 19:58:40 bcik go-librespot[2819]: time="2026-10-12T19:58:40+02:00" level=debug msg="completed challenge" Oct 12 19:58:40 bcik go-librespot[2819]: time="2026-10-12T19:58:40+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 19:58:40 bcik go-librespot[2819]: time="2026-10-12T19:58:40+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 19:58:40 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 19:58:40 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 19:58:42 bcik volumio[2319]: info: Initializing connection to go-librespot Websocket Oct 12 19:58:42 bcik volumio[2319]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 19:58:44 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 75. Oct 12 19:58:44 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:58:44 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:58:44 bcik go-librespot[2843]: go-librespot daemon starting... Oct 12 19:58:44 bcik go-librespot[2844]: time="2026-10-12T19:58:44+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 19:58:44 bcik go-librespot[2844]: time="2026-10-12T19:58:44+02:00" level=debug msg="app state loaded" Oct 12 19:58:44 bcik go-librespot[2844]: time="2026-10-12T19:58:44+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 19:58:44 bcik go-librespot[2844]: time="2026-10-12T19:58:44+02: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]" Oct 12 19:58:44 bcik go-librespot[2844]: time="2026-10-12T19:58:44+02: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]" Oct 12 19:58:44 bcik go-librespot[2844]: time="2026-10-12T19:58:44+02: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]" Oct 12 19:58:44 bcik go-librespot[2844]: time="2026-10-12T19:58:44+02:00" level=info msg="zeroconf server listening on port 34159" Oct 12 19:58:44 bcik go-librespot[2844]: time="2026-10-12T19:58:44+02:00" level=debug msg="obtained new client token: AAFh5UbFSTz3qpb8AUmYCbRXF7/3QOONaiQE+dUKhycn8Te/uSrcjzpPgdI7yQQlKSX7mghlWzFdLrVecEJW/MtHn6erTnmSv/7Q7h6t3uvAKBhOM0fVI2U0V4Kdgp4i72EASRgSIiPRxbhjNTbnHjWhhYNWWUaiYLSoFP9xKx7H01Q9mL1O8EU2/66hxyZiQkwVT3+nFTAuv7I5paxOP217FXFfKB0V2tPd45vc1kR/jBm5mk/h" Oct 12 19:58:44 bcik go-librespot[2844]: time="2026-10-12T19:58:44+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 19:58:45 bcik go-librespot[2844]: time="2026-10-12T19:58:45+02:00" level=debug msg="completed keyexchange" Oct 12 19:58:45 bcik go-librespot[2844]: time="2026-10-12T19:58:45+02:00" level=debug msg="completed challenge" Oct 12 19:58:45 bcik go-librespot[2844]: time="2026-10-12T19:58:45+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 19:58:45 bcik go-librespot[2844]: time="2026-10-12T19:58:45+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 19:58:45 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 19:58:45 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 19:58:45 bcik volumio[2319]: info: Initializing connection to go-librespot Websocket Oct 12 19:58:45 bcik volumio[2319]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 19:58:48 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 76. Oct 12 19:58:48 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:58:48 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:58:48 bcik go-librespot[2853]: go-librespot daemon starting... Oct 12 19:58:48 bcik go-librespot[2854]: time="2026-10-12T19:58:48+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 19:58:48 bcik go-librespot[2854]: time="2026-10-12T19:58:48+02:00" level=debug msg="app state loaded" Oct 12 19:58:48 bcik go-librespot[2854]: time="2026-10-12T19:58:48+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 19:58:48 bcik go-librespot[2854]: time="2026-10-12T19:58:48+02: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]" Oct 12 19:58:48 bcik go-librespot[2854]: time="2026-10-12T19:58:48+02: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]" Oct 12 19:58:48 bcik go-librespot[2854]: time="2026-10-12T19:58:48+02: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]" Oct 12 19:58:48 bcik go-librespot[2854]: time="2026-10-12T19:58:48+02:00" level=info msg="zeroconf server listening on port 36811" Oct 12 19:58:48 bcik go-librespot[2854]: time="2026-10-12T19:58:48+02:00" level=debug msg="obtained new client token: AAEyINo0ZefBmy9rc01amF9BEV3qkCOOaLM4QDkbqiBzPPdTOR8mWfo5koLJg7r5cMeNK0vkyGiIwFeCNBt3V3yf7l9q47A0h4EkFrL+VTSqMbJFbM031sJWhHiNe6E+18cqRKZB8H47lXWvkpACHDLzY3F+5lExiyW3BUt+hyqqhtFYE+PHHFjB3ADNxTfSX2Z4arorbfqJaj6HLPeml0Kw2zQnUR8R0mG4sEx38MIQILUt/qU13Qo=" Oct 12 19:58:48 bcik go-librespot[2854]: time="2026-10-12T19:58:48+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 19:58:48 bcik go-librespot[2854]: time="2026-10-12T19:58:48+02:00" level=debug msg="completed keyexchange" Oct 12 19:58:48 bcik go-librespot[2854]: time="2026-10-12T19:58:48+02:00" level=debug msg="completed challenge" Oct 12 19:58:48 bcik volumio[2319]: info: Initializing connection to go-librespot Websocket Oct 12 19:58:48 bcik go-librespot[2854]: time="2026-10-12T19:58:48+02:00" level=debug msg="new websocket client" Oct 12 19:58:48 bcik volumio[2319]: info: Connection to go-librespot Websocket established Oct 12 19:58:48 bcik go-librespot[2854]: time="2026-10-12T19:58:48+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 19:58:48 bcik go-librespot[2854]: time="2026-10-12T19:58:48+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 19:58:48 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 19:58:48 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 19:58:48 bcik volumio[2319]: info: Connection to go-librespot Websocket closed Oct 12 19:58:51 bcik volumio[2319]: info: Getting Spotify volume Oct 12 19:58:51 bcik volumio[2319]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 19:58:51 bcik volumio[2319]: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 19:58:51 bcik volumio[2319]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Oct 12 19:58:51 bcik volumio[2319]: errno: -111, Oct 12 19:58:51 bcik volumio[2319]: code: 'ECONNREFUSED', Oct 12 19:58:51 bcik volumio[2319]: syscall: 'connect', Oct 12 19:58:51 bcik volumio[2319]: address: '127.0.0.1', Oct 12 19:58:51 bcik volumio[2319]: port: 9879, Oct 12 19:58:51 bcik volumio[2319]: response: undefined Oct 12 19:58:51 bcik volumio[2319]: } Oct 12 19:58:51 bcik volumio[2319]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 19:58:51 bcik sudo[2877]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-12 19:57' Oct 12 19:58:51 bcik sudo[2877]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 19:58:52 bcik sudo[2877]: pam_unix(sudo:session): session closed for user root Oct 12 19:58:52 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 77. Oct 12 19:58:52 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:58:52 bcik volumio-remote-updater[9031]: [2026-10-12 19:58:52] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Oct 12 19:58:52 bcik volumio5-onboarding[32041]: time=2026-10-12T19:58:52.057+02:00 level=ERROR msg="failed reading message" error="websocket: close 1006 (abnormal closure): unexpected EOF" Oct 12 19:58:52 bcik volumio-remote-updater[9031]: [2026-10-12 19:58:52] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Oct 12 19:58:52 bcik volumio5-onboarding[32041]: time=2026-10-12T19:58:52.057+02:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Oct 12 19:58:52 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:58:52 bcik systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Oct 12 19:58:52 bcik go-librespot[2882]: go-librespot daemon starting... Oct 12 19:58:52 bcik go-librespot[2883]: time="2026-10-12T19:58:52+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 19:58:52 bcik go-librespot[2883]: time="2026-10-12T19:58:52+02:00" level=debug msg="app state loaded" Oct 12 19:58:52 bcik go-librespot[2883]: time="2026-10-12T19:58:52+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 19:58:52 bcik systemd[1]: volumio.service: Failed with result 'exit-code'. Oct 12 19:58:52 bcik systemd[1]: volumio.service: Consumed 6.908s CPU time. Oct 12 19:58:52 bcik systemd[1]: Started dynamicswap.service - dynamicswap service. Oct 12 19:58:52 bcik systemd[1]: dynamicswap.service: Deactivated successfully. Oct 12 19:58:52 bcik go-librespot[2883]: time="2026-10-12T19:58:52+02: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]" Oct 12 19:58:52 bcik go-librespot[2883]: time="2026-10-12T19:58:52+02: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]" Oct 12 19:58:52 bcik go-librespot[2883]: time="2026-10-12T19:58:52+02: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]" Oct 12 19:58:52 bcik go-librespot[2883]: time="2026-10-12T19:58:52+02:00" level=info msg="zeroconf server listening on port 42665" Oct 12 19:58:52 bcik go-librespot[2883]: time="2026-10-12T19:58:52+02:00" level=debug msg="obtained new client token: AAGeBKIV9adQHsjSepVbeo+ZwzbNSK/EksB5Z3CzRiL7/A21x5Xl9u5w4ZF7vshKDqr7jdNXaBojIzk59wofnfMx8qDKTe6zgid7S0BMIPnyzjAYJL4u/o5x2oz8M4zPxZLzxAm6mtaFOWk4gsV5O44y09Wod0NSFoQJjG21t1vNMhj1zu1I5crWrggskIUvj8T9TQyno63LrxmxAqZeqdoyKZYi0mr5PvvgY80Klaanpf9PNmar" Oct 12 19:58:52 bcik go-librespot[2883]: time="2026-10-12T19:58:52+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 19:58:52 bcik go-librespot[2883]: time="2026-10-12T19:58:52+02:00" level=debug msg="completed keyexchange" Oct 12 19:58:52 bcik go-librespot[2883]: time="2026-10-12T19:58:52+02:00" level=debug msg="completed challenge" Oct 12 19:58:52 bcik systemd[1]: volumio.service: Scheduled restart job, restart counter is at 22616. Oct 12 19:58:52 bcik go-librespot[2883]: time="2026-10-12T19:58:52+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 19:58:52 bcik systemd[1]: Started dynamicswap.service - dynamicswap service. Oct 12 19:58:52 bcik systemd[1]: Stopped volumio.service - Volumio Backend Module. Oct 12 19:58:52 bcik systemd[1]: volumio.service: Consumed 6.908s CPU time. Oct 12 19:58:52 bcik systemd[1]: Started volumio.service - Volumio Backend Module. Oct 12 19:58:52 bcik systemd[1]: dynamicswap.service: Deactivated successfully. Oct 12 19:58:52 bcik go-librespot[2883]: time="2026-10-12T19:58:52+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 19:58:52 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 19:58:52 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 19:58:52 bcik volumio[2899]: info: ------------------------------------------- Oct 12 19:58:52 bcik volumio[2899]: info: ----- Volumio3 ---- Oct 12 19:58:52 bcik volumio[2899]: info: ------------------------------------------- Oct 12 19:58:52 bcik volumio[2899]: info: ----- System startup ---- Oct 12 19:58:52 bcik volumio[2899]: info: ------------------------------------------- Oct 12 19:58:52 bcik volumio[2899]: info: MYVOLUMIO Environment detected Oct 12 19:58:52 bcik volumio[2899]: info: Plugin folders cleanup Oct 12 19:58:52 bcik volumio[2899]: info: Scanning into folder /volumio/app/plugins/ Oct 12 19:58:52 bcik volumio[2899]: info: Scanning category audio_interface Oct 12 19:58:52 bcik volumio[2899]: info: Scanning category miscellanea Oct 12 19:58:52 bcik volumio[2899]: info: Scanning category music_service Oct 12 19:58:52 bcik volumio[2899]: info: Scanning category plugins.json Oct 12 19:58:52 bcik volumio[2899]: info: Scanning category system_controller Oct 12 19:58:52 bcik volumio[2899]: info: Scanning category user_interface Oct 12 19:58:52 bcik volumio[2899]: info: Scanning into folder /data/plugins/ Oct 12 19:58:52 bcik volumio[2899]: info: Scanning category music_service Oct 12 19:58:52 bcik volumio[2899]: info: Plugin folders cleanup completed Oct 12 19:58:52 bcik volumio[2899]: info: ------------------------------------------- Oct 12 19:58:52 bcik volumio[2899]: info: ----- Core plugins startup ---- Oct 12 19:58:52 bcik volumio[2899]: info: ------------------------------------------- Oct 12 19:58:52 bcik volumio[2899]: info: Loading plugins from folder /volumio/app/plugins/ Oct 12 19:58:52 bcik volumio[2899]: info: Adding plugin upnp to MyMusic Plugins Oct 12 19:58:52 bcik volumio[2899]: info: Adding plugin airplay_emulation to MyMusic Plugins Oct 12 19:58:52 bcik volumio[2899]: info: Adding plugin upnp_browser to MyMusic Plugins Oct 12 19:58:52 bcik volumio[2899]: info: Loading plugins from folder /data/plugins/ Oct 12 19:58:52 bcik volumio[2899]: info: Loading plugin "system"... Oct 12 19:58:52 bcik volumio[2899]: info: Loading plugin "appearance"... Oct 12 19:58:53 bcik volumio[2899]: info: Loading plugin "network"... Oct 12 19:58:53 bcik volumio[2899]: info: Refreshing Cached IP Addresses Oct 12 19:58:53 bcik volumio[2899]: info: Loading plugin "services"... Oct 12 19:58:53 bcik volumio[2899]: info: Loading plugin "volumio5onboarding"... Oct 12 19:58:53 bcik sudo[2927]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 12 19:58:53 bcik sudo[2927]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 19:58:53 bcik sudo[2929]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 12 19:58:53 bcik sudo[2929]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 19:58:53 bcik sudo[2927]: pam_unix(sudo:session): session closed for user root Oct 12 19:58:53 bcik volumio[2899]: info: Loading plugin "alsa_controller"... Oct 12 19:58:53 bcik sudo[2929]: pam_unix(sudo:session): session closed for user root Oct 12 19:58:53 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 12 19:58:53 bcik volumio[2899]: info: Loading plugin "wizard"... Oct 12 19:58:53 bcik volumio[2899]: info: Loading plugin "networkfs"... Oct 12 19:58:53 bcik volumio[2899]: info: Starting Udev Watcher for removable devices Oct 12 19:58:53 bcik volumio[2899]: info: Ignoring mount for partition: boot Oct 12 19:58:53 bcik volumio[2899]: info: Ignoring mount for partition: volumio Oct 12 19:58:53 bcik volumio[2899]: info: Ignoring mount for partition: volumio_data Oct 12 19:58:53 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 12 19:58:53 bcik volumio[2899]: info: Loading plugin "volumio_command_line_client"... Oct 12 19:58:53 bcik volumio[2899]: info: Loading plugin "upnp"... Oct 12 19:58:53 bcik volumio[2899]: info: [1791827933116] Starting Upmpd Daemon Oct 12 19:58:53 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 12 19:58:53 bcik volumio[2899]: info: Loading plugin "my_music"... Oct 12 19:58:53 bcik volumio[2899]: info: Loading plugin "mpd"... Oct 12 19:58:53 bcik volumio[2899]: info: Loading plugin "upnp_browser"... Oct 12 19:58:53 bcik volumio[2899]: info: Starting UPNP Browser Oct 12 19:58:53 bcik volumio[2899]: info: Loading plugin "alarm-clock"... Oct 12 19:58:53 bcik volumio[2899]: info: Loading plugin "airplay_emulation"... Oct 12 19:58:53 bcik volumio[2899]: info: Starting Shairport Sync Oct 12 19:58:53 bcik volumio[2899]: info: Loading plugin "last_100"... Oct 12 19:58:53 bcik volumio[2899]: info: Loading plugin "webradio"... Oct 12 19:58:53 bcik volumio[2899]: info: Loading plugin "i2s_dacs"... Oct 12 19:58:53 bcik volumio[2899]: info: Loading plugin "volumiodiscovery"... Oct 12 19:58:53 bcik volumio[2899]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 12 19:58:53 bcik volumio[2899]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 12 19:58:53 bcik volumio[2899]: *** WARNING *** For more information see Oct 12 19:58:53 bcik volumio[2899]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 12 19:58:53 bcik volumio[2899]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 12 19:58:53 bcik volumio[2899]: *** WARNING *** For more information see Oct 12 19:58:53 bcik node[2899]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 12 19:58:53 bcik node[2899]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 12 19:58:53 bcik node[2899]: *** WARNING *** For more information see Oct 12 19:58:53 bcik node[2899]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 12 19:58:53 bcik node[2899]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 12 19:58:53 bcik node[2899]: *** WARNING *** For more information see Oct 12 19:58:53 bcik volumio[2899]: info: Applying required configuration parameters for plugin volumiodiscovery Oct 12 19:58:53 bcik volumio[2899]: info: Discovery: Started advertising with name: Bącik Oct 12 19:58:53 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 12 19:58:53 bcik volumio[2899]: info: Loading plugin "spop"... Oct 12 19:58:53 bcik volumio[2899]: info: Loading plugin "outputs"... Oct 12 19:58:53 bcik volumio[2899]: info: Loading plugin "albumart"... Oct 12 19:58:53 bcik volumio[2899]: info: Plugin example_plugin is not enabled Oct 12 19:58:53 bcik volumio[2899]: info: Loading plugin "inputs"... Oct 12 19:58:53 bcik volumio[2899]: info: Loading plugin "updater_comm"... Oct 12 19:58:53 bcik volumio[2899]: info: Plugin mpdemulation is not enabled Oct 12 19:58:53 bcik volumio[2899]: info: Loading plugin "rest_api"... Oct 12 19:58:53 bcik volumio[2899]: info: Loading plugin "websocket"... Oct 12 19:58:53 bcik volumio[2899]: info: Starting Socket.io Server version 1.7.4 Oct 12 19:58:53 bcik volumio[2899]: info: Loading plugin "radio_browser"... Oct 12 19:58:53 bcik volumio[2959]: Forking 3 albumart workers Oct 12 19:58:53 bcik volumio[2899]: info: Loading i18n strings for locale pl Oct 12 19:58:53 bcik volumio[2899]: Updating browse sources language Oct 12 19:58:53 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 19:58:53 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 19:58:53 bcik volumio[2899]: info: CoreCommandRouter::initPlayerControls Oct 12 19:58:53 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:58:53 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:58:53 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:58:53 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:58:53 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:58:53 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:58:53 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:58:53 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:58:53 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 19:58:53 bcik volumio[2899]: Express server listening on port 3000 Oct 12 19:58:53 bcik volumio[2899]: [Metrics] WebUI: 1s 295.87ms Oct 12 19:58:53 bcik volumio[2899]: info: CoreStateMachine::resetVolumioState Oct 12 19:58:53 bcik volumio[2899]: info: CoreStateMachine::getcurrentVolume Oct 12 19:58:53 bcik volumio[2899]: info: CoreCommandRouter::volumioRetrievevolume Oct 12 19:58:53 bcik volumio[2899]: info: Volumio Network Manager: Network status updated: 1 Oct 12 19:58:53 bcik volumio[2899]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 12 19:58:53 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 19:58:53 bcik volumio[2899]: info: Reloading queue from file Oct 12 19:58:54 bcik volumio[2899]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 12 19:58:54 bcik volumio[2899]: info: CoreStateMachine::setRepeat false single undefined Oct 12 19:58:54 bcik volumio[2899]: info: CoreStateMachine::pushState Oct 12 19:58:54 bcik volumio[2899]: info: CorePlayQueue::getTrack 0 Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::volumioPushState Oct 12 19:58:54 bcik volumio[2899]: info: CoreStateMachine::setRandom false Oct 12 19:58:54 bcik volumio[2899]: info: CoreStateMachine::pushState Oct 12 19:58:54 bcik volumio[2899]: info: CorePlayQueue::getTrack 0 Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::volumioPushState Oct 12 19:58:54 bcik volumio[2899]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Oct 12 19:58:54 bcik volumio[2899]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04171 Oct 12 19:58:54 bcik volumio[2899]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Oct 12 19:58:54 bcik volumio[2899]: info: VolumeController:: Volume=41 Mute =false Oct 12 19:58:54 bcik volumio[2899]: info: CoreStateMachine::pushState Oct 12 19:58:54 bcik volumio[2899]: info: CorePlayQueue::getTrack 0 Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::volumioPushState Oct 12 19:58:54 bcik volumio[2899]: info: CoreStateMachine::updateTrackBlock Oct 12 19:58:54 bcik volumio[2899]: info: CorePlayQueue::getTrackBlock Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::volumioRetrievevolume Oct 12 19:58:54 bcik volumio[2899]: info: Setting Device type: Raspberry PI Oct 12 19:58:54 bcik volumio[2899]: info: Completed loading Core Plugins Oct 12 19:58:54 bcik volumio[2899]: info: Preparing to generate the ALSA configuration file Oct 12 19:58:54 bcik volumio[2899]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 12 19:58:54 bcik volumio[2899]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 12 19:58:54 bcik volumio[2899]: info: VolumeController:: Volume=41 Mute =false Oct 12 19:58:54 bcik volumio[2899]: info: CoreStateMachine::pushState Oct 12 19:58:54 bcik volumio[2899]: info: CorePlayQueue::getTrack 0 Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::volumioPushState Oct 12 19:58:54 bcik volumio[2899]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 12 19:58:54 bcik volumio[2899]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 12 19:58:54 bcik volumio[2899]: info: Asound.conf file unchanged, so no further update is needed Oct 12 19:58:54 bcik volumio[2899]: info: Output device has changed, restarting MPD Oct 12 19:58:54 bcik volumio[2899]: info: Output device has changed, restarting Shairport Sync Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 19:58:54 bcik sudo[3013]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 12 19:58:54 bcik volumio[2971]: Starting albumart workers Oct 12 19:58:54 bcik sudo[3013]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 19:58:54 bcik sudo[3015]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 12 19:58:54 bcik sudo[3015]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 19:58:54 bcik sudo[3013]: pam_unix(sudo:session): session closed for user root Oct 12 19:58:54 bcik volumio[2899]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 12 19:58:54 bcik volumio[2899]: info: ___________ START PLUGINS ___________ Oct 12 19:58:54 bcik volumio[2899]: info: ControllerMpd::onStart: Initializing MPD Oct 12 19:58:54 bcik volumio[2899]: info: Creating MPD Configuration file Oct 12 19:58:54 bcik volumio[2969]: Starting albumart workers Oct 12 19:58:54 bcik systemd[1]: Stopping mpd.service - Music Player Daemon... Oct 12 19:58:54 bcik sudo[3023]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Oct 12 19:58:54 bcik sudo[3023]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 19:58:54 bcik sudo[3025]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 12 19:58:54 bcik sudo[3025]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 19:58:54 bcik sudo[3025]: pam_unix(sudo:session): session closed for user root Oct 12 19:58:54 bcik systemd[1]: mpd.service: Deactivated successfully. Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 12 19:58:54 bcik systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 12 19:58:54 bcik volumio[2899]: info: [1791827934158] CoreMusicLibrary::Adding element Serwery Mediów Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 19:58:54 bcik systemd[1]: mpd.socket: Deactivated successfully. Oct 12 19:58:54 bcik systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 12 19:58:54 bcik systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 12 19:58:54 bcik volumio[2899]: info: UPNP Browser: Client initialized successfully Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 19:58:54 bcik sudo[3030]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 12 19:58:54 bcik sudo[3030]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 19:58:54 bcik volumio[2899]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 19:58:54 bcik systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 12 19:58:54 bcik systemd[1]: Starting mpd.service - Music Player Daemon... Oct 12 19:58:54 bcik volumio[2899]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 12 19:58:54 bcik volumio[2899]: info: [1791827934198] CoreMusicLibrary::Adding element Last_100 Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 12 19:58:54 bcik volumio[2899]: info: [1791827934201] CoreMusicLibrary::Adding element Webradio Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 19:58:54 bcik sudo[3023]: pam_unix(sudo:session): session closed for user root Oct 12 19:58:54 bcik systemd[1]: mpd.service: Deactivated successfully. Oct 12 19:58:54 bcik systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 12 19:58:54 bcik systemd[1]: mpd.socket: Deactivated successfully. Oct 12 19:58:54 bcik systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 12 19:58:54 bcik systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 12 19:58:54 bcik volumio[2899]: info: Initializing BBC Radios Oct 12 19:58:54 bcik systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 12 19:58:54 bcik systemd[1]: Starting mpd.service - Music Player Daemon... Oct 12 19:58:54 bcik volumio[2970]: Starting albumart workers Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 19:58:54 bcik volumio[2899]: info: Creating Spotify config file Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:58:54 bcik sudo[3044]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 12 19:58:54 bcik sudo[3044]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 12 19:58:54 bcik sudo[3044]: pam_unix(sudo:session): session closed for user root Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 12 19:58:54 bcik volumio[2899]: info: [1791827934360] CoreMusicLibrary::Adding element Radio Browser Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 19:58:54 bcik volumio[2899]: Cannot find translation for source Radio Browser Oct 12 19:58:54 bcik volumio[2899]: info: Volumio Calling Home Oct 12 19:58:54 bcik volumio[2899]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 12 19:58:54 bcik volumio[2899]: info: MPD Permissions set Oct 12 19:58:54 bcik volumio[2899]: info: MPD Permissions set Oct 12 19:58:54 bcik volumio[2899]: info: Spotify config file written Oct 12 19:58:54 bcik sudo[3081]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Oct 12 19:58:54 bcik sudo[3081]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 19:58:54 bcik volumio[2899]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Oct 12 19:58:54 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:58:54 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:58:54 bcik go-librespot[3084]: go-librespot daemon starting... Oct 12 19:58:54 bcik sudo[3081]: pam_unix(sudo:session): session closed for user root Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:58:54 bcik go-librespot[3095]: time="2026-10-12T19:58:54+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 19:58:54 bcik go-librespot[3095]: time="2026-10-12T19:58:54+02:00" level=debug msg="app state loaded" Oct 12 19:58:54 bcik volumio[2899]: info: No need to fix Spotify hosts Oct 12 19:58:54 bcik go-librespot[3095]: time="2026-10-12T19:58:54+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 19:58:54 bcik volumio[2899]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 19:58:54 bcik volumio[2899]: info: Volumio called home Oct 12 19:58:54 bcik volumio[2899]: info: Discovery: adding f1ed5fb6-e21d-47c8-819b-29842600355e Oct 12 19:58:54 bcik volumio[2899]: info: Discovery: Found device Bącik Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::volumioGetState Oct 12 19:58:54 bcik volumio[2899]: info: CorePlayQueue::getTrack 0 Oct 12 19:58:54 bcik volumio[2899]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 19:58:54 bcik volumio[2899]: info: Starting Shairport Sync Oct 12 19:58:54 bcik volumio[2899]: info: Starting Shairport Sync Oct 12 19:58:54 bcik sudo[3103]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 12 19:58:54 bcik sudo[3103]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 19:58:54 bcik volumio[2899]: info: Starting Shairport Sync Oct 12 19:58:54 bcik volumio[2899]: info: Discovery: this is already registered, f1ed5fb6-e21d-47c8-819b-29842600355e Oct 12 19:58:54 bcik volumio[2899]: info: Discovery: Found device Bącik Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::volumioGetState Oct 12 19:58:54 bcik volumio[2899]: info: CorePlayQueue::getTrack 0 Oct 12 19:58:54 bcik sudo[3105]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 12 19:58:54 bcik sudo[3105]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 19:58:54 bcik sudo[3108]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 12 19:58:54 bcik go-librespot[3095]: time="2026-10-12T19:58:54+02: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]" Oct 12 19:58:54 bcik go-librespot[3095]: time="2026-10-12T19:58:54+02: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]" Oct 12 19:58:54 bcik go-librespot[3095]: time="2026-10-12T19:58:54+02: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]" Oct 12 19:58:54 bcik sudo[3108]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 19:58:54 bcik systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 12 19:58:54 bcik systemd[1]: shairport-sync.service: Deactivated successfully. Oct 12 19:58:54 bcik systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 12 19:58:54 bcik systemd[1]: shairport-sync.service: Consumed 1.544s CPU time. Oct 12 19:58:54 bcik go-librespot[3095]: time="2026-10-12T19:58:54+02:00" level=info msg="zeroconf server listening on port 34079" Oct 12 19:58:54 bcik volumio[2899]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 19:58:54 bcik volumio[2899]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 19:58:54 bcik volumio[2899]: info: CoreCommandRouter::volumioGetState Oct 12 19:58:54 bcik volumio[2899]: info: CorePlayQueue::getTrack 0 Oct 12 19:58:54 bcik systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 12 19:58:54 bcik sudo[3103]: pam_unix(sudo:session): session closed for user root Oct 12 19:58:54 bcik sudo[3105]: pam_unix(sudo:session): session closed for user root Oct 12 19:58:54 bcik volumio[2899]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 19:58:54 bcik sudo[3108]: pam_unix(sudo:session): session closed for user root Oct 12 19:58:54 bcik volumio[2899]: info: Shairport-Sync Started Oct 12 19:58:54 bcik volumio[2899]: Error adding Membership: Error: addMembership EINVAL Oct 12 19:58:54 bcik volumio[2899]: info: Shairport-Sync Started Oct 12 19:58:54 bcik volumio[2899]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 19:58:54 bcik volumio[2899]: info: Shairport-Sync Started Oct 12 19:58:54 bcik volumio[2899]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 19:58:54 bcik volumio[2899]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 19:58:54 bcik go-librespot[3095]: time="2026-10-12T19:58:54+02:00" level=debug msg="obtained new client token: AAGRmki5X5LHJqmenl4ngvNlwujrrtDEVuZkpBiboGK5KB/EDpB3IWfE29WRl6sddMxiHtw+u21St/2bl0VqiYJN36Ni/FqjL/4XkZ5b+IwbMh0pu3QztPkEWw5CDhJ54N1S6QCQwVQpoBLOr4RgNn7ZoyFHjs7qmhV5UpUvpIoDSIDLSKg3thu/HYT+V51cnupI/ugpL5aBLe+O7CW7k+ClyEpXbzdWcoE517m0zJ00Wq/HCRABgQI=" Oct 12 19:58:54 bcik volumio[2899]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 19:58:54 bcik volumio[2899]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 19:58:54 bcik go-librespot[3095]: time="2026-10-12T19:58:54+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 19:58:54 bcik volumio[2899]: info: An error occurred while refreshing Spotify Token Error: Bad Request Oct 12 19:58:54 bcik go-librespot[3095]: time="2026-10-12T19:58:54+02:00" level=debug msg="completed keyexchange" Oct 12 19:58:54 bcik go-librespot[3095]: time="2026-10-12T19:58:54+02:00" level=debug msg="completed challenge" Oct 12 19:58:54 bcik go-librespot[3095]: time="2026-10-12T19:58:54+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 19:58:54 bcik mpd[3057]: 2026-10-12T19:58:54 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 12 19:58:54 bcik systemd[1]: Started mpd.service - Music Player Daemon. Oct 12 19:58:54 bcik sudo[3015]: pam_unix(sudo:session): session closed for user root Oct 12 19:58:54 bcik sudo[3030]: pam_unix(sudo:session): session closed for user root Oct 12 19:58:54 bcik volumio[2899]: info: Completed starting Core Plugins Oct 12 19:58:54 bcik volumio[2899]: info: ------------------------------------------- Oct 12 19:58:54 bcik volumio[2899]: info: ----- MyVolumio plugins startup ---- Oct 12 19:58:54 bcik volumio[2899]: info: ------------------------------------------- Oct 12 19:58:54 bcik volumio[2899]: info: [MyVolumio PluginManager] Fetching plans data.... Oct 12 19:58:54 bcik go-librespot[3095]: time="2026-10-12T19:58:54+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 19:58:54 bcik volumio[2899]: error: MPD error: The expression evaluated to a falsy value: Oct 12 19:58:54 bcik volumio[2899]: assert.ok(self.idling) Oct 12 19:58:54 bcik volumio[2899]: error: The expression evaluated to a falsy value: Oct 12 19:58:54 bcik volumio[2899]: assert.ok(self.idling) Oct 12 19:58:54 bcik volumio[2899]: info: MPD running with PID3057 Oct 12 19:58:54 bcik volumio[2899]: ,establishing connection Oct 12 19:58:54 bcik volumio[2899]: error: updateQueue error: null Oct 12 19:58:54 bcik volumio[2899]: error: updateQueue error: null Oct 12 19:58:54 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 19:58:54 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 19:58:57 bcik volumio-remote-updater[9031]: [2026-10-12 19:58:57] [connect] Successful connection Oct 12 19:58:57 bcik volumio-remote-updater[9031]: [2026-10-12 19:58:57] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1791827937 101 Oct 12 19:58:57 bcik volumio[2899]: 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: 3 Oct 12 19:58:57 bcik volumio[2899]: info: go-librespot daemon successfully initialized Oct 12 19:58:58 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 78. Oct 12 19:58:58 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:58:58 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:58:58 bcik go-librespot[3132]: go-librespot daemon starting... Oct 12 19:58:58 bcik go-librespot[3133]: time="2026-10-12T19:58:58+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 19:58:58 bcik go-librespot[3133]: time="2026-10-12T19:58:58+02:00" level=debug msg="app state loaded" Oct 12 19:58:58 bcik go-librespot[3133]: time="2026-10-12T19:58:58+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 19:58:58 bcik go-librespot[3133]: time="2026-10-12T19:58:58+02: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]" Oct 12 19:58:58 bcik go-librespot[3133]: time="2026-10-12T19:58:58+02: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]" Oct 12 19:58:58 bcik go-librespot[3133]: time="2026-10-12T19:58:58+02: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]" Oct 12 19:58:58 bcik go-librespot[3133]: time="2026-10-12T19:58:58+02:00" level=info msg="zeroconf server listening on port 45035" Oct 12 19:58:58 bcik go-librespot[3133]: time="2026-10-12T19:58:58+02:00" level=debug msg="obtained new client token: AAGQm9/QTrzgJrjNoqxEgn91VsqulUq52VWYngUzkVSKDYJBPrCj5ngYwHe8HhA+7myszzyJJMF9T5hBllIOsPyyuS6t8cUYy+9Ob0UgpFrEzV+vWrEJYK/WWv4aA+SD7CL38mSFBXeC3ULnSZt0KmJFz9bWGmu/jnmflbscSRiw7SHWkt3LR4C+PTB1A1Ul1Sbw32OtM9dAML92NoqMJZc94eoL21SeRLezJtft6ghQ71IXyI6I" Oct 12 19:58:58 bcik go-librespot[3133]: time="2026-10-12T19:58:58+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 19:58:58 bcik go-librespot[3133]: time="2026-10-12T19:58:58+02:00" level=debug msg="completed keyexchange" Oct 12 19:58:58 bcik go-librespot[3133]: time="2026-10-12T19:58:58+02:00" level=debug msg="completed challenge" Oct 12 19:58:58 bcik go-librespot[3133]: time="2026-10-12T19:58:58+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 19:58:58 bcik go-librespot[3133]: time="2026-10-12T19:58:58+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 19:58:58 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 19:58:58 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 19:58:59 bcik volumio[2899]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Oct 12 19:59:00 bcik volumio[2899]: info: Initializing connection to go-librespot Websocket Oct 12 19:59:00 bcik volumio[2899]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 19:59:01 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 79. Oct 12 19:59:01 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:59:01 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:59:01 bcik go-librespot[3142]: go-librespot daemon starting... Oct 12 19:59:01 bcik go-librespot[3143]: time="2026-10-12T19:59:01+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 19:59:01 bcik go-librespot[3143]: time="2026-10-12T19:59:01+02:00" level=debug msg="app state loaded" Oct 12 19:59:01 bcik go-librespot[3143]: time="2026-10-12T19:59:01+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 19:59:01 bcik go-librespot[3143]: time="2026-10-12T19:59:01+02: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]" Oct 12 19:59:01 bcik go-librespot[3143]: time="2026-10-12T19:59:01+02: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]" Oct 12 19:59:01 bcik go-librespot[3143]: time="2026-10-12T19:59:01+02: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]" Oct 12 19:59:01 bcik go-librespot[3143]: time="2026-10-12T19:59:01+02:00" level=info msg="zeroconf server listening on port 39935" Oct 12 19:59:01 bcik go-librespot[3143]: time="2026-10-12T19:59:01+02:00" level=debug msg="obtained new client token: AAFR7gtdD7PMsAXpdJu8+GRk4KAG/Z5icQqzY7wiN2fbFP4LijgUkcdM9KWs6cv7hr5MTtfV/nfJSVR+ukJGzQs7dVxurAaKJzIkjZsd28zyUPNmEHVc7bKrfcqxujeTBGvubW1Ah1LHEmbpUfI+bUzRQP5n4b7cRrO4D/KhcFnZPIVbcivMxOx1+CP3ieR1sZ18GpZ1NDVxXqV7dJDr+i612PJUEqF/qqNX/UG2Q9RidH3UvnMYGQk=" Oct 12 19:59:01 bcik go-librespot[3143]: time="2026-10-12T19:59:01+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 19:59:01 bcik go-librespot[3143]: time="2026-10-12T19:59:01+02:00" level=debug msg="completed keyexchange" Oct 12 19:59:01 bcik go-librespot[3143]: time="2026-10-12T19:59:01+02:00" level=debug msg="completed challenge" Oct 12 19:59:01 bcik go-librespot[3143]: time="2026-10-12T19:59:01+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 19:59:01 bcik go-librespot[3143]: time="2026-10-12T19:59:01+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 19:59:01 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 19:59:01 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 19:59:03 bcik volumio[2899]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Oct 12 19:59:03 bcik volumio[2899]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Oct 12 19:59:03 bcik volumio[2899]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Oct 12 19:59:03 bcik volumio[2899]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Oct 12 19:59:03 bcik volumio[2899]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Oct 12 19:59:03 bcik volumio[2899]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Oct 12 19:59:03 bcik volumio[2899]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Oct 12 19:59:03 bcik volumio[2899]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Oct 12 19:59:03 bcik volumio[2899]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Oct 12 19:59:03 bcik volumio[2899]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Oct 12 19:59:03 bcik volumio[2899]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Oct 12 19:59:03 bcik volumio[2899]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Oct 12 19:59:03 bcik volumio[2899]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Oct 12 19:59:03 bcik volumio[2899]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Oct 12 19:59:03 bcik volumio[2899]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Oct 12 19:59:03 bcik volumio[2899]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Oct 12 19:59:03 bcik volumio[2899]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Oct 12 19:59:03 bcik volumio[2899]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Oct 12 19:59:03 bcik volumio[2899]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Oct 12 19:59:03 bcik volumio[2899]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Oct 12 19:59:03 bcik volumio[2899]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Oct 12 19:59:03 bcik volumio[2899]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Oct 12 19:59:03 bcik volumio[2899]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Oct 12 19:59:03 bcik volumio[2899]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Oct 12 19:59:03 bcik volumio[2899]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Oct 12 19:59:03 bcik volumio[2899]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Oct 12 19:59:03 bcik volumio[2899]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Oct 12 19:59:03 bcik volumio[2899]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Oct 12 19:59:03 bcik volumio[2899]: info: Adding plugin bluetooth to MyMusic Plugins Oct 12 19:59:03 bcik volumio[2899]: info: Adding plugin multiroom to MyMusic Plugins Oct 12 19:59:03 bcik volumio[2899]: info: Adding plugin metavolumio to MyMusic Plugins Oct 12 19:59:03 bcik volumio[2899]: info: Adding plugin cd_controller to MyMusic Plugins Oct 12 19:59:03 bcik volumio[2899]: info: Adding plugin qobuzconnect to MyMusic Plugins Oct 12 19:59:03 bcik volumio[2899]: info: Adding plugin smart_inputs to MyMusic Plugins Oct 12 19:59:03 bcik volumio[2899]: info: Adding plugin tidalconnect to MyMusic Plugins Oct 12 19:59:03 bcik volumio[2899]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Oct 12 19:59:03 bcik volumio[2899]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Oct 12 19:59:03 bcik volumio[2899]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Oct 12 19:59:03 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 19:59:03 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 19:59:03 bcik volumio[2899]: info: Starting MyVolumio Remote Streaming Endpoints Oct 12 19:59:03 bcik volumio[2899]: info: MyVolumio login type: Token Oct 12 19:59:03 bcik volumio[2899]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Oct 12 19:59:03 bcik volumio[2899]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Oct 12 19:59:03 bcik volumio[2899]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Oct 12 19:59:03 bcik volumio[2899]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Oct 12 19:59:03 bcik volumio[2899]: info: Streaming services startup Oct 12 19:59:03 bcik volumio[2899]: info: Starting Streaming Daemon Oct 12 19:59:03 bcik volumio[2899]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Oct 12 19:59:03 bcik sudo[3168]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 12 19:59:03 bcik sudo[3168]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 19:59:03 bcik sudo[3168]: pam_unix(sudo:session): session closed for user root Oct 12 19:59:03 bcik sudo[3175]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 12 19:59:03 bcik sudo[3175]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 19:59:03 bcik volumio[2899]: error: Cannot start Volumio Streaming Daemon Oct 12 19:59:03 bcik volumio[2899]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 12 19:59:03 bcik volumio[2899]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 12 19:59:03 bcik sudo[3177]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 12 19:59:03 bcik sudo[3177]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 19:59:03 bcik sudo[3175]: pam_unix(sudo:session): session closed for user root Oct 12 19:59:03 bcik sudo[3177]: pam_unix(sudo:session): session closed for user root Oct 12 19:59:03 bcik sudo[3181]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Oct 12 19:59:03 bcik sudo[3181]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 19:59:03 bcik volumio[2899]: info: Initializing connection to go-librespot Websocket Oct 12 19:59:03 bcik volumio[2899]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 19:59:03 bcik sudo[3181]: pam_unix(sudo:session): session closed for user root Oct 12 19:59:03 bcik volumio[2899]: info: Upmpdcli Daemon Started Oct 12 19:59:03 bcik volumio[2899]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Oct 12 19:59:04 bcik volumio[2899]: info: MyVolumio token set successfully Oct 12 19:59:04 bcik volumio[2899]: info: MYVOLUMIO: Adding device Oct 12 19:59:04 bcik volumio[2899]: info: MYVOLUMIO: Evaluating Server Oct 12 19:59:04 bcik volumio[2899]: info: MyVolumio status changed Oct 12 19:59:04 bcik volumio[2899]: info: Streaming services startup Oct 12 19:59:04 bcik volumio[2899]: info: Starting Streaming Daemon Oct 12 19:59:04 bcik volumio[2899]: info: Removing browser output: myVolumio user plan is not superstar Oct 12 19:59:04 bcik volumio[2899]: info: Removing audio output: Oct 12 19:59:04 bcik volumio[2899]: info: Stoppping Tunnel 1 Oct 12 19:59:04 bcik sudo[3204]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 12 19:59:04 bcik sudo[3204]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 19:59:04 bcik sudo[3206]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Oct 12 19:59:04 bcik sudo[3206]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 19:59:04 bcik 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. Oct 12 19:59:04 bcik 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. Oct 12 19:59:04 bcik sudo[3204]: pam_unix(sudo:session): session closed for user root Oct 12 19:59:04 bcik 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. Oct 12 19:59:04 bcik 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. Oct 12 19:59:04 bcik volumio[2899]: error: Cannot start Volumio Streaming Daemon Oct 12 19:59:04 bcik volumio[2899]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 12 19:59:04 bcik volumio[2899]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 12 19:59:04 bcik 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. Oct 12 19:59:04 bcik 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. Oct 12 19:59:04 bcik sudo[3206]: pam_unix(sudo:session): session closed for user root Oct 12 19:59:04 bcik volumio[2899]: info: Remote SSH Stopped Oct 12 19:59:04 bcik volumio[2899]: info: Setting Geolocation for MyVolumio to eu6 Oct 12 19:59:04 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 19:59:04 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 19:59:04 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 19:59:05 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 80. Oct 12 19:59:05 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:59:05 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:59:05 bcik go-librespot[3209]: go-librespot daemon starting... Oct 12 19:59:05 bcik go-librespot[3210]: time="2026-10-12T19:59:05+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 19:59:05 bcik go-librespot[3210]: time="2026-10-12T19:59:05+02:00" level=debug msg="app state loaded" Oct 12 19:59:05 bcik go-librespot[3210]: time="2026-10-12T19:59:05+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 19:59:05 bcik go-librespot[3210]: time="2026-10-12T19:59:05+02: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]" Oct 12 19:59:05 bcik go-librespot[3210]: time="2026-10-12T19:59:05+02: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]" Oct 12 19:59:05 bcik go-librespot[3210]: time="2026-10-12T19:59:05+02: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]" Oct 12 19:59:05 bcik go-librespot[3210]: time="2026-10-12T19:59:05+02:00" level=info msg="zeroconf server listening on port 46329" Oct 12 19:59:05 bcik go-librespot[3210]: time="2026-10-12T19:59:05+02:00" level=debug msg="obtained new client token: AAHhTHgo/3gCFC2Ekfo9GUUTZtVPofoVu3uJtl3Jzlj7n5uqSJplHpz31+Ywmp+CqHffFgCgnFFM12oZyIHHDGihblyj61bpagccUOJbJZvio3UXn7ruQfnVpp9k+Hrxjf80Un/rZFR7tvOdnZhOYwV2G0k1+yz5gTGTG2PSWi9ThKQ0xprNwsMay4koqL9jpIjtA8OF3MnZD3D1VlsdGaYZsUhAAO23RjcJzJoyi93y06kP0T5g" Oct 12 19:59:05 bcik go-librespot[3210]: time="2026-10-12T19:59:05+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 19:59:05 bcik go-librespot[3210]: time="2026-10-12T19:59:05+02:00" level=debug msg="completed keyexchange" Oct 12 19:59:05 bcik go-librespot[3210]: time="2026-10-12T19:59:05+02:00" level=debug msg="completed challenge" Oct 12 19:59:05 bcik volumio[2899]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Oct 12 19:59:05 bcik go-librespot[3210]: time="2026-10-12T19:59:05+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 19:59:05 bcik go-librespot[3210]: time="2026-10-12T19:59:05+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 19:59:05 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 19:59:05 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 19:59:05 bcik volumio[2899]: info: Updating MyVolumio device info Oct 12 19:59:05 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 19:59:05 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 19:59:05 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 19:59:06 bcik volumio[2899]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Oct 12 19:59:06 bcik volumio[2899]: info: Initializing connection to go-librespot Websocket Oct 12 19:59:06 bcik volumio[2899]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 19:59:08 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 81. Oct 12 19:59:08 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:59:08 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:59:08 bcik go-librespot[3221]: go-librespot daemon starting... Oct 12 19:59:08 bcik go-librespot[3222]: time="2026-10-12T19:59:08+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 19:59:08 bcik go-librespot[3222]: time="2026-10-12T19:59:08+02:00" level=debug msg="app state loaded" Oct 12 19:59:08 bcik go-librespot[3222]: time="2026-10-12T19:59:08+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 19:59:08 bcik go-librespot[3222]: time="2026-10-12T19:59:08+02: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]" Oct 12 19:59:08 bcik go-librespot[3222]: time="2026-10-12T19:59:08+02: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]" Oct 12 19:59:08 bcik go-librespot[3222]: time="2026-10-12T19:59:08+02: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]" Oct 12 19:59:08 bcik go-librespot[3222]: time="2026-10-12T19:59:08+02:00" level=info msg="zeroconf server listening on port 34111" Oct 12 19:59:08 bcik go-librespot[3222]: time="2026-10-12T19:59:08+02:00" level=debug msg="obtained new client token: AAHhwM5r1daFOKqXxs1jvidcFD9yG0ikPXT2CZQ4a7RaUeWnJy0HSOWY98CC+M7Ng7eWEPCve3LNFElJZ4tbtBHysEiXwW0gx+mYG5Dng/cAwqpku9aBXKpxB3k16I0Sp7Yq8bPvF27PpbomnJD2aDXTzgBH4wtuTkbJ5knl0mghiP9c5aAOeVm/QpNSCxkqCVvZnczsHTHxgMpVMonwjM5hbF/9/DBMhcJhYLmjGo6kv1mGbMZCDzI=" Oct 12 19:59:08 bcik go-librespot[3222]: time="2026-10-12T19:59:08+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 19:59:08 bcik go-librespot[3222]: time="2026-10-12T19:59:08+02:00" level=debug msg="completed keyexchange" Oct 12 19:59:08 bcik go-librespot[3222]: time="2026-10-12T19:59:08+02:00" level=debug msg="completed challenge" Oct 12 19:59:08 bcik go-librespot[3222]: time="2026-10-12T19:59:08+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 19:59:08 bcik go-librespot[3222]: time="2026-10-12T19:59:08+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 19:59:08 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 19:59:08 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 19:59:09 bcik volumio[2899]: info: MYVOLUMIO: Adding device Oct 12 19:59:09 bcik volumio[2899]: info: MYVOLUMIO: Evaluating Server Oct 12 19:59:09 bcik volumio[2899]: info: Initializing connection to go-librespot Websocket Oct 12 19:59:09 bcik volumio[2899]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 19:59:10 bcik volumio[2899]: info: Setting Geolocation for MyVolumio to eu4 Oct 12 19:59:10 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 19:59:10 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 19:59:10 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 19:59:10 bcik volumio[2899]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Oct 12 19:59:11 bcik volumio[2899]: info: Updating MyVolumio device info Oct 12 19:59:11 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 19:59:11 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 19:59:11 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 19:59:11 bcik volumio[2899]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Oct 12 19:59:12 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 82. Oct 12 19:59:12 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:59:12 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:59:12 bcik go-librespot[3249]: go-librespot daemon starting... Oct 12 19:59:12 bcik go-librespot[3250]: time="2026-10-12T19:59:12+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 19:59:12 bcik go-librespot[3250]: time="2026-10-12T19:59:12+02:00" level=debug msg="app state loaded" Oct 12 19:59:12 bcik go-librespot[3250]: time="2026-10-12T19:59:12+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 19:59:12 bcik go-librespot[3250]: time="2026-10-12T19:59:12+02: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]" Oct 12 19:59:12 bcik go-librespot[3250]: time="2026-10-12T19:59:12+02: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]" Oct 12 19:59:12 bcik go-librespot[3250]: time="2026-10-12T19:59:12+02: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]" Oct 12 19:59:12 bcik go-librespot[3250]: time="2026-10-12T19:59:12+02:00" level=info msg="zeroconf server listening on port 34273" Oct 12 19:59:12 bcik go-librespot[3250]: time="2026-10-12T19:59:12+02:00" level=debug msg="obtained new client token: AAHEO+ig2/+DdPgGCj66K+I7TqIaAoX7y6wh/y0XY212rMnEu6ktEdHbMuXQMzob9YkjvGuaIVgl1TgdjbklqiQkb+INI0o1vUIYxU7rwq/kSelKGHsssAYQsdU7kBwhq4cBmaxE5ABPGmq8lW5KRpH5fsiDHws+xa5vHKgj8Euw8ErAFVL1w2SXmp9p7JdMWdVUpqsB+10vzC2KLiPPJ0z+c6ITgrc4HJVUbHD5L+ecCkSKTNfO" Oct 12 19:59:12 bcik go-librespot[3250]: time="2026-10-12T19:59:12+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 19:59:12 bcik go-librespot[3250]: time="2026-10-12T19:59:12+02:00" level=debug msg="completed keyexchange" Oct 12 19:59:12 bcik go-librespot[3250]: time="2026-10-12T19:59:12+02:00" level=debug msg="completed challenge" Oct 12 19:59:12 bcik go-librespot[3250]: time="2026-10-12T19:59:12+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 19:59:12 bcik go-librespot[3250]: time="2026-10-12T19:59:12+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 19:59:12 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 19:59:12 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 19:59:12 bcik volumio[2899]: info: Initializing connection to go-librespot Websocket Oct 12 19:59:12 bcik volumio[2899]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 19:59:15 bcik volumio[2899]: info: Initializing connection to go-librespot Websocket Oct 12 19:59:15 bcik volumio[2899]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 19:59:15 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 83. Oct 12 19:59:15 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:59:15 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:59:15 bcik go-librespot[3273]: go-librespot daemon starting... Oct 12 19:59:15 bcik go-librespot[3274]: time="2026-10-12T19:59:15+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 19:59:15 bcik go-librespot[3274]: time="2026-10-12T19:59:15+02:00" level=debug msg="app state loaded" Oct 12 19:59:15 bcik go-librespot[3274]: time="2026-10-12T19:59:15+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 19:59:15 bcik go-librespot[3274]: time="2026-10-12T19:59:15+02: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]" Oct 12 19:59:15 bcik go-librespot[3274]: time="2026-10-12T19:59:15+02: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]" Oct 12 19:59:15 bcik go-librespot[3274]: time="2026-10-12T19:59:15+02: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]" Oct 12 19:59:15 bcik go-librespot[3274]: time="2026-10-12T19:59:15+02:00" level=info msg="zeroconf server listening on port 35931" Oct 12 19:59:15 bcik go-librespot[3274]: time="2026-10-12T19:59:15+02:00" level=debug msg="obtained new client token: AAEsexBs79jjKN4yNhfnZE0nqv3e9G0f11ltVcFl/RfSWDCXRrpq9i54UBbAkLQ76MXJ3rfdmybJfheFHVoCbpzM8CU4gEMJJcrobx9uyC2ya66frxm5JuFG6td3RxzXz7nRD+85zl+J6DmmlyeEs1fxxi0YK80OR5qO+lm953tdnJZ6TuWmQIvaLQ083VuCj9XtDA9QvPspooxDWILxhhLG1FH1o/bybSZrLIHGlk+q62W/DWpef1U=" Oct 12 19:59:15 bcik go-librespot[3274]: time="2026-10-12T19:59:15+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 19:59:15 bcik go-librespot[3274]: time="2026-10-12T19:59:15+02:00" level=debug msg="completed keyexchange" Oct 12 19:59:15 bcik go-librespot[3274]: time="2026-10-12T19:59:15+02:00" level=debug msg="completed challenge" Oct 12 19:59:15 bcik go-librespot[3274]: time="2026-10-12T19:59:15+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 19:59:15 bcik go-librespot[3274]: time="2026-10-12T19:59:15+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 19:59:15 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 19:59:15 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 19:59:18 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 12 19:59:18 bcik volumio[2899]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Oct 12 19:59:18 bcik volumio[2899]: info: CoreCommandRouter::volumioGetState Oct 12 19:59:18 bcik volumio[2899]: info: CorePlayQueue::getTrack 0 Oct 12 19:59:18 bcik volumio[2899]: info: Initializing connection to go-librespot Websocket Oct 12 19:59:18 bcik volumio[2899]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 19:59:19 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 84. Oct 12 19:59:19 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:59:19 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:59:19 bcik go-librespot[3283]: go-librespot daemon starting... Oct 12 19:59:19 bcik go-librespot[3284]: time="2026-10-12T19:59:19+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 19:59:19 bcik go-librespot[3284]: time="2026-10-12T19:59:19+02:00" level=debug msg="app state loaded" Oct 12 19:59:19 bcik go-librespot[3284]: time="2026-10-12T19:59:19+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 19:59:19 bcik go-librespot[3284]: time="2026-10-12T19:59:19+02: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]" Oct 12 19:59:19 bcik go-librespot[3284]: time="2026-10-12T19:59:19+02: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]" Oct 12 19:59:19 bcik go-librespot[3284]: time="2026-10-12T19:59:19+02: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]" Oct 12 19:59:19 bcik go-librespot[3284]: time="2026-10-12T19:59:19+02:00" level=info msg="zeroconf server listening on port 33245" Oct 12 19:59:19 bcik go-librespot[3284]: time="2026-10-12T19:59:19+02:00" level=debug msg="obtained new client token: AAGFKJuPqWpkwktri9XZFuobZWw5ei0ZW+zD3m/8DW+SSgnV+du7kE+eDh95A+aOoRj3t1jIYuiCqTeE5+ROVAiMpZWdOcdfqvKJ7Gl6GR28/XkcZkfrOoXjzze5MKi6CVr1DFyloVm52hbLRtGWAMaxLXoSVpK6Eat3XPTuIbi9EegC1Q6af+bYbTzXk78HWA9P9mmKxdu8zOAZulMpTh/dmplyr6ToHkx5KVMHXXFSyivGLaiR" Oct 12 19:59:19 bcik go-librespot[3284]: time="2026-10-12T19:59:19+02: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" Oct 12 19:59:19 bcik go-librespot[3284]: time="2026-10-12T19:59:19+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:443, retrying with a different AP" error="dial tcp 34.158.1.133:443: connect: connection refused" Oct 12 19:59:19 bcik go-librespot[3284]: time="2026-10-12T19:59:19+02:00" level=debug msg="connected to ap-gew4.spotify.com:80" Oct 12 19:59:19 bcik go-librespot[3284]: time="2026-10-12T19:59:19+02:00" level=debug msg="completed keyexchange" Oct 12 19:59:19 bcik go-librespot[3284]: time="2026-10-12T19:59:19+02:00" level=debug msg="completed challenge" Oct 12 19:59:19 bcik go-librespot[3284]: time="2026-10-12T19:59:19+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 19:59:19 bcik go-librespot[3284]: time="2026-10-12T19:59:19+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 19:59:19 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 19:59:19 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 19:59:21 bcik volumio[2899]: info: Initializing connection to go-librespot Websocket Oct 12 19:59:21 bcik volumio[2899]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 19:59:22 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 85. Oct 12 19:59:22 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:59:22 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:59:22 bcik go-librespot[3294]: go-librespot daemon starting... Oct 12 19:59:22 bcik go-librespot[3295]: time="2026-10-12T19:59:22+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 19:59:22 bcik go-librespot[3295]: time="2026-10-12T19:59:22+02:00" level=debug msg="app state loaded" Oct 12 19:59:22 bcik go-librespot[3295]: time="2026-10-12T19:59:22+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 19:59:22 bcik go-librespot[3295]: time="2026-10-12T19:59:22+02: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]" Oct 12 19:59:22 bcik go-librespot[3295]: time="2026-10-12T19:59:22+02: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]" Oct 12 19:59:22 bcik go-librespot[3295]: time="2026-10-12T19:59:22+02: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]" Oct 12 19:59:22 bcik go-librespot[3295]: time="2026-10-12T19:59:22+02:00" level=info msg="zeroconf server listening on port 46799" Oct 12 19:59:22 bcik go-librespot[3295]: time="2026-10-12T19:59:22+02:00" level=debug msg="obtained new client token: AAGNHIOaPByNVXTFsiroUtkrdwU0OJbgjLS+28ZPdmV307hkZ0HNCOzwy63obzzWMVg3IexjwT2ioh7Txcw7B5MJ8M/cCEBFT/aIt3JYGl6jT0hZY8ZqnW29jzqg1Edt5Fl6qD/eOA38jaL/A6SY+LloB5Z9GftpHdltreiayf8OnSMA0gQLqOoe85XeR3bzG9MM99r+XP7t982Qeq5sR9Y9MxFRgADbdk46hVo7JQIXUMF54zLhFNo=" Oct 12 19:59:22 bcik go-librespot[3295]: time="2026-10-12T19:59:22+02: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" Oct 12 19:59:22 bcik go-librespot[3295]: time="2026-10-12T19:59:22+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Oct 12 19:59:22 bcik go-librespot[3295]: time="2026-10-12T19:59:22+02:00" level=debug msg="completed keyexchange" Oct 12 19:59:22 bcik go-librespot[3295]: time="2026-10-12T19:59:22+02:00" level=debug msg="completed challenge" Oct 12 19:59:22 bcik go-librespot[3295]: time="2026-10-12T19:59:22+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 19:59:22 bcik go-librespot[3295]: time="2026-10-12T19:59:22+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 19:59:22 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 19:59:22 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 19:59:23 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:59:23 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:59:23 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Oct 12 19:59:23 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Oct 12 19:59:23 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Oct 12 19:59:23 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Oct 12 19:59:23 bcik volumio[2899]: info: CoreCommandRouter::volumioGetBrowseSources Oct 12 19:59:23 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 12 19:59:23 bcik volumio[2899]: error: MyVolumio Plugin failed to authenticate in a timely fashion Oct 12 19:59:23 bcik volumio[2899]: info: Completed starting MyVolumio Plugin Oct 12 19:59:23 bcik volumio[2899]: [Metrics] CommandRouter: 30s 793.45ms Oct 12 19:59:23 bcik volumio[2899]: info: CoreCommandRouter::volumiosetStartupVolume Oct 12 19:59:23 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 19:59:23 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 19:59:23 bcik volumio[2899]: info: CoreCommandRouter::Close All Modals sent Oct 12 19:59:23 bcik volumio[2899]: info: CoreCommandRouter::Close All Modals sent Oct 12 19:59:24 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 12 19:59:24 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 19:59:24 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 12 19:59:24 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Oct 12 19:59:24 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 12 19:59:24 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Oct 12 19:59:24 bcik volumio-remote-updater[9031]: Test mode disabled Oct 12 19:59:24 bcik volumio-remote-updater[9031]: Alpha mode disabled Oct 12 19:59:24 bcik volumio-remote-updater[9031]: Alpha legacy test mode disabled Oct 12 19:59:24 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Oct 12 19:59:24 bcik volumio[2899]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Oct 12 19:59:24 bcik volumio[2899]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Oct 12 19:59:24 bcik volumio[2899]: info: Initializing connection to go-librespot Websocket Oct 12 19:59:24 bcik volumio[2899]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 19:59:26 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 86. Oct 12 19:59:26 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:59:26 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:59:26 bcik go-librespot[3325]: go-librespot daemon starting... Oct 12 19:59:26 bcik go-librespot[3326]: time="2026-10-12T19:59:26+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 19:59:26 bcik go-librespot[3326]: time="2026-10-12T19:59:26+02:00" level=debug msg="app state loaded" Oct 12 19:59:26 bcik go-librespot[3326]: time="2026-10-12T19:59:26+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 19:59:26 bcik go-librespot[3326]: time="2026-10-12T19:59:26+02: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]" Oct 12 19:59:26 bcik go-librespot[3326]: time="2026-10-12T19:59:26+02: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]" Oct 12 19:59:26 bcik go-librespot[3326]: time="2026-10-12T19:59:26+02: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]" Oct 12 19:59:26 bcik go-librespot[3326]: time="2026-10-12T19:59:26+02:00" level=info msg="zeroconf server listening on port 36149" Oct 12 19:59:26 bcik go-librespot[3326]: time="2026-10-12T19:59:26+02:00" level=debug msg="obtained new client token: AAGeoAS40XSCE4shdrgq9MZVVJoZ4gdR0U/0sta7n6Dd+JnxEpiTMOCZfFsZ/GKJp4xcL5v7OdMZ5dfNWjPrwkK8qMv+b2pmbgP31uIAmxtNQZ5fXaiRWi8f94g77/QHr4tKK9DU33nddN84B2rVF4Dpd7/Q6U019OmrpprKIOxzz3kNFqROH7U6EMoeBeyH+GB/0nUjtbyTWosSreZKsetky4CYOnr6YfisiaH1PFbQgBDdBWSv" Oct 12 19:59:26 bcik go-librespot[3326]: time="2026-10-12T19:59:26+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 19:59:26 bcik go-librespot[3326]: time="2026-10-12T19:59:26+02:00" level=debug msg="completed keyexchange" Oct 12 19:59:26 bcik go-librespot[3326]: time="2026-10-12T19:59:26+02:00" level=debug msg="completed challenge" Oct 12 19:59:26 bcik go-librespot[3326]: time="2026-10-12T19:59:26+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 19:59:26 bcik go-librespot[3326]: time="2026-10-12T19:59:26+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 19:59:26 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 19:59:26 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 19:59:27 bcik volumio[2899]: info: Initializing connection to go-librespot Websocket Oct 12 19:59:27 bcik volumio[2899]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 19:59:29 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 87. Oct 12 19:59:29 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:59:29 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:59:29 bcik go-librespot[3335]: go-librespot daemon starting... Oct 12 19:59:29 bcik go-librespot[3336]: time="2026-10-12T19:59:29+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 19:59:29 bcik go-librespot[3336]: time="2026-10-12T19:59:29+02:00" level=debug msg="app state loaded" Oct 12 19:59:29 bcik go-librespot[3336]: time="2026-10-12T19:59:29+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 19:59:29 bcik go-librespot[3336]: time="2026-10-12T19:59:29+02: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]" Oct 12 19:59:29 bcik go-librespot[3336]: time="2026-10-12T19:59:29+02: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]" Oct 12 19:59:29 bcik go-librespot[3336]: time="2026-10-12T19:59:29+02: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]" Oct 12 19:59:29 bcik go-librespot[3336]: time="2026-10-12T19:59:29+02:00" level=info msg="zeroconf server listening on port 43787" Oct 12 19:59:29 bcik go-librespot[3336]: time="2026-10-12T19:59:29+02:00" level=debug msg="obtained new client token: AAGL+3nfEKPKDbDvcBgacnnLnwo3c9Gu6WDCg1sh3xW6NM1BhgdO35VwLjuj4Y+SN9neQIisWyn0QGSBhvCbvY/RsQW4qMNVbQNUfYuWb4ST7epiH4Ln5+X/mNGfPcOP8kuDO7YygdknBAoc/J5hYmVPXQt3eO6CqTqbdi8Uw6wOdkCqMoYz3HOy7iBRuwTQcSnodajldrfo42rrrVUA5rJJFikCaJUQdd05PXKmOH5/8dUOVotqj/8=" Oct 12 19:59:29 bcik go-librespot[3336]: time="2026-10-12T19:59:29+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 19:59:29 bcik go-librespot[3336]: time="2026-10-12T19:59:29+02:00" level=debug msg="completed keyexchange" Oct 12 19:59:29 bcik go-librespot[3336]: time="2026-10-12T19:59:29+02:00" level=debug msg="completed challenge" Oct 12 19:59:29 bcik go-librespot[3336]: time="2026-10-12T19:59:29+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 19:59:29 bcik go-librespot[3336]: time="2026-10-12T19:59:29+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 19:59:29 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 19:59:29 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 19:59:30 bcik volumio[2899]: info: BOOT COMPLETED Oct 12 19:59:30 bcik volumio[2899]: info: Initializing connection to go-librespot Websocket Oct 12 19:59:30 bcik volumio[2899]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 19:59:33 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 88. Oct 12 19:59:33 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:59:33 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:59:33 bcik go-librespot[3345]: go-librespot daemon starting... Oct 12 19:59:33 bcik go-librespot[3346]: time="2026-10-12T19:59:33+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 19:59:33 bcik go-librespot[3346]: time="2026-10-12T19:59:33+02:00" level=debug msg="app state loaded" Oct 12 19:59:33 bcik go-librespot[3346]: time="2026-10-12T19:59:33+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 19:59:33 bcik go-librespot[3346]: time="2026-10-12T19:59:33+02: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]" Oct 12 19:59:33 bcik go-librespot[3346]: time="2026-10-12T19:59:33+02: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]" Oct 12 19:59:33 bcik go-librespot[3346]: time="2026-10-12T19:59:33+02: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]" Oct 12 19:59:33 bcik go-librespot[3346]: time="2026-10-12T19:59:33+02:00" level=info msg="zeroconf server listening on port 44541" Oct 12 19:59:33 bcik go-librespot[3346]: time="2026-10-12T19:59:33+02:00" level=debug msg="obtained new client token: AAETT6Vg4BYoMwlYrY1IaKP5PDxVm5JDBgYBq6jzHn48ujh5aD/7tnY4RMgcPgAvEynmdMU0kQ0/iF9Xhi6sLS8uyVN+OrSejeiqYXW29NTZf7oDpCK1ELHpfKgJfwD8rfi9LWJuBMfGnOKzYrYeT2hwIkCThSC/eImnAvi2uZznMCUNhWv1Z2Yq9k8y1eRkYAbPbcomOrGCVCRRkpNOHUrwDm3wexdvpg0o090wcTUlkCZ1BUgT4qU=" Oct 12 19:59:33 bcik go-librespot[3346]: time="2026-10-12T19:59:33+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 19:59:33 bcik go-librespot[3346]: time="2026-10-12T19:59:33+02:00" level=debug msg="completed keyexchange" Oct 12 19:59:33 bcik go-librespot[3346]: time="2026-10-12T19:59:33+02:00" level=debug msg="completed challenge" Oct 12 19:59:33 bcik go-librespot[3346]: time="2026-10-12T19:59:33+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 19:59:33 bcik go-librespot[3346]: time="2026-10-12T19:59:33+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 19:59:33 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 19:59:33 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 19:59:33 bcik volumio[2899]: info: Initializing connection to go-librespot Websocket Oct 12 19:59:33 bcik volumio[2899]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 19:59:36 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 89. Oct 12 19:59:36 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:59:36 bcik volumio[2899]: info: Initializing connection to go-librespot Websocket Oct 12 19:59:36 bcik volumio[2899]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 19:59:36 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:59:36 bcik go-librespot[3369]: go-librespot daemon starting... Oct 12 19:59:36 bcik go-librespot[3370]: time="2026-10-12T19:59:36+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 19:59:36 bcik go-librespot[3370]: time="2026-10-12T19:59:36+02:00" level=debug msg="app state loaded" Oct 12 19:59:36 bcik go-librespot[3370]: time="2026-10-12T19:59:36+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 19:59:36 bcik go-librespot[3370]: time="2026-10-12T19:59:36+02: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]" Oct 12 19:59:36 bcik go-librespot[3370]: time="2026-10-12T19:59:36+02: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]" Oct 12 19:59:36 bcik go-librespot[3370]: time="2026-10-12T19:59:36+02: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]" Oct 12 19:59:36 bcik go-librespot[3370]: time="2026-10-12T19:59:36+02:00" level=info msg="zeroconf server listening on port 38991" Oct 12 19:59:36 bcik go-librespot[3370]: time="2026-10-12T19:59:36+02:00" level=debug msg="obtained new client token: AAEY3gdWlAT9M1ZItDEAEwRIA0bqVsMQB7w1uIYDKO+CTTEgylAE82e4V/rzLJFkvo0FonVyFtI3SXcvdcqV5pHtmL/eTW0lhn9Ys2U2RqmpqeYv7LsfEM0hBcgdNLOBuJjl/YR1MdwQK5eQKi1bt8cpxZY+KgeCijL7zz9YGggeVKGEMqyVR3pZkf1/uZAJzSrzgbFrpxQpeuNiEaQO1fqvW2vt/ODwVMnl0jUNZLDKC/qHIO3kzJ4=" Oct 12 19:59:36 bcik go-librespot[3370]: time="2026-10-12T19:59:36+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 19:59:36 bcik go-librespot[3370]: time="2026-10-12T19:59:36+02:00" level=debug msg="completed keyexchange" Oct 12 19:59:36 bcik go-librespot[3370]: time="2026-10-12T19:59:36+02:00" level=debug msg="completed challenge" Oct 12 19:59:36 bcik go-librespot[3370]: time="2026-10-12T19:59:36+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 19:59:36 bcik go-librespot[3370]: time="2026-10-12T19:59:36+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 19:59:36 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 19:59:36 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 19:59:39 bcik volumio[2899]: info: Initializing connection to go-librespot Websocket Oct 12 19:59:39 bcik volumio[2899]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 19:59:40 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 90. Oct 12 19:59:40 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:59:40 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:59:40 bcik go-librespot[3379]: go-librespot daemon starting... Oct 12 19:59:40 bcik go-librespot[3380]: time="2026-10-12T19:59:40+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 19:59:40 bcik go-librespot[3380]: time="2026-10-12T19:59:40+02:00" level=debug msg="app state loaded" Oct 12 19:59:40 bcik go-librespot[3380]: time="2026-10-12T19:59:40+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 19:59:40 bcik go-librespot[3380]: time="2026-10-12T19:59:40+02: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]" Oct 12 19:59:40 bcik go-librespot[3380]: time="2026-10-12T19:59:40+02: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]" Oct 12 19:59:40 bcik go-librespot[3380]: time="2026-10-12T19:59:40+02: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]" Oct 12 19:59:40 bcik go-librespot[3380]: time="2026-10-12T19:59:40+02:00" level=info msg="zeroconf server listening on port 33667" Oct 12 19:59:40 bcik go-librespot[3380]: time="2026-10-12T19:59:40+02:00" level=debug msg="obtained new client token: AAE7itzq66WMrc5JnsLR4O1PVlRbgsjJqosK4UmJxegN/CxqNrh7BGwW3T4RJXgzj5nZRZSabijTD6EgbTDFkNohujRV51vCHWiW2G6993v26ug0erVxky3xC0wBRQ/3jpJ5LKYQuQFzmx4VYS1dyR8WpYz1fJp24ZrpCH75adpEV3a29BUOY9u1k5hVnCdbJ0k+MPgt09Cfy6PevZELUEXsnIGfluci22ZPp2g0Kx4XMX370jX7" Oct 12 19:59:40 bcik go-librespot[3380]: time="2026-10-12T19:59:40+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 19:59:40 bcik go-librespot[3380]: time="2026-10-12T19:59:40+02:00" level=debug msg="completed keyexchange" Oct 12 19:59:40 bcik go-librespot[3380]: time="2026-10-12T19:59:40+02:00" level=debug msg="completed challenge" Oct 12 19:59:40 bcik go-librespot[3380]: time="2026-10-12T19:59:40+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 19:59:40 bcik go-librespot[3380]: time="2026-10-12T19:59:40+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 19:59:40 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 19:59:40 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 19:59:42 bcik volumio[2899]: info: Initializing connection to go-librespot Websocket Oct 12 19:59:42 bcik volumio[2899]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 19:59:43 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 91. Oct 12 19:59:43 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:59:43 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:59:43 bcik go-librespot[3404]: go-librespot daemon starting... Oct 12 19:59:43 bcik go-librespot[3405]: time="2026-10-12T19:59:43+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 19:59:43 bcik go-librespot[3405]: time="2026-10-12T19:59:43+02:00" level=debug msg="app state loaded" Oct 12 19:59:43 bcik go-librespot[3405]: time="2026-10-12T19:59:43+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 19:59:43 bcik go-librespot[3405]: time="2026-10-12T19:59:43+02: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]" Oct 12 19:59:43 bcik go-librespot[3405]: time="2026-10-12T19:59:43+02: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]" Oct 12 19:59:43 bcik go-librespot[3405]: time="2026-10-12T19:59:43+02: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]" Oct 12 19:59:43 bcik go-librespot[3405]: time="2026-10-12T19:59:43+02:00" level=info msg="zeroconf server listening on port 34525" Oct 12 19:59:43 bcik go-librespot[3405]: time="2026-10-12T19:59:43+02:00" level=debug msg="obtained new client token: AAGLBHEB0zCCQNBNAQ9Rr4KAoz5XPUY8pdjrA8AbNR4EjRfqEGJWWJtm5shDCjsR5bflg9zLrKfuNpX3Cm6Z8qyOjp9wgEbr5zNf5hhCW8Un0RspIOsXWCWMiGx8oSWyTxX2Vcu6MKRmjIRbGQ85QpUdi5flAPawDYlX7GZvzogwLubvNYH6Z3kwUHh2U0GEZAsR9NWGtT/w9C9FeRjiTIp0S+PqOYGoiu/h0StD272qoh+W3RkKCA8=" Oct 12 19:59:43 bcik go-librespot[3405]: time="2026-10-12T19:59:43+02: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" Oct 12 19:59:43 bcik go-librespot[3405]: time="2026-10-12T19:59:43+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Oct 12 19:59:43 bcik go-librespot[3405]: time="2026-10-12T19:59:43+02:00" level=debug msg="completed keyexchange" Oct 12 19:59:43 bcik go-librespot[3405]: time="2026-10-12T19:59:43+02:00" level=debug msg="completed challenge" Oct 12 19:59:43 bcik go-librespot[3405]: time="2026-10-12T19:59:43+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 19:59:43 bcik go-librespot[3405]: time="2026-10-12T19:59:43+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 19:59:43 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 19:59:43 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 19:59:45 bcik volumio[2899]: info: Initializing connection to go-librespot Websocket Oct 12 19:59:45 bcik volumio[2899]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 19:59:47 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 92. Oct 12 19:59:47 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:59:47 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:59:47 bcik go-librespot[3414]: go-librespot daemon starting... Oct 12 19:59:47 bcik go-librespot[3415]: time="2026-10-12T19:59:47+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 19:59:47 bcik go-librespot[3415]: time="2026-10-12T19:59:47+02:00" level=debug msg="app state loaded" Oct 12 19:59:47 bcik go-librespot[3415]: time="2026-10-12T19:59:47+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 19:59:47 bcik go-librespot[3415]: time="2026-10-12T19:59:47+02: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]" Oct 12 19:59:47 bcik go-librespot[3415]: time="2026-10-12T19:59:47+02: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]" Oct 12 19:59:47 bcik go-librespot[3415]: time="2026-10-12T19:59:47+02: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]" Oct 12 19:59:47 bcik go-librespot[3415]: time="2026-10-12T19:59:47+02:00" level=info msg="zeroconf server listening on port 36193" Oct 12 19:59:47 bcik go-librespot[3415]: time="2026-10-12T19:59:47+02:00" level=debug msg="obtained new client token: AAFsYaKIZJeCyKl5YM+5W2E5g5k1jEExr9YBj/XN1bx8r8Peqhlf4/5/O7Ns2k7i8V8UtKekub83G3HZINQhVZZMPulMKLKTjC2Q+CCA/ZTIbb5TMfPnikPT1ZCDeqdHQo+mYNvC94bom66n5ud8Nq8GIXvowRX1BPr5KQPH/MGVUjaKLM/F0vs0GMTA2dLB7S5zW29GuybXd8lwS0r7ZPOBJBdsZLrmnp7SHyntxNb8w2pnmx9I" Oct 12 19:59:47 bcik go-librespot[3415]: time="2026-10-12T19:59:47+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 19:59:47 bcik go-librespot[3415]: time="2026-10-12T19:59:47+02:00" level=debug msg="completed keyexchange" Oct 12 19:59:47 bcik go-librespot[3415]: time="2026-10-12T19:59:47+02:00" level=debug msg="completed challenge" Oct 12 19:59:47 bcik go-librespot[3415]: time="2026-10-12T19:59:47+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 19:59:47 bcik go-librespot[3415]: time="2026-10-12T19:59:47+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 19:59:47 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 19:59:47 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 19:59:48 bcik volumio[2899]: info: Initializing connection to go-librespot Websocket Oct 12 19:59:48 bcik volumio[2899]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 19:59:50 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 93. Oct 12 19:59:50 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:59:50 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:59:50 bcik go-librespot[3425]: go-librespot daemon starting... Oct 12 19:59:50 bcik go-librespot[3426]: time="2026-10-12T19:59:50+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 19:59:50 bcik go-librespot[3426]: time="2026-10-12T19:59:50+02:00" level=debug msg="app state loaded" Oct 12 19:59:50 bcik go-librespot[3426]: time="2026-10-12T19:59:50+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 19:59:50 bcik go-librespot[3426]: time="2026-10-12T19:59:50+02: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]" Oct 12 19:59:50 bcik go-librespot[3426]: time="2026-10-12T19:59:50+02: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]" Oct 12 19:59:50 bcik go-librespot[3426]: time="2026-10-12T19:59:50+02: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]" Oct 12 19:59:50 bcik go-librespot[3426]: time="2026-10-12T19:59:50+02:00" level=info msg="zeroconf server listening on port 46699" Oct 12 19:59:50 bcik go-librespot[3426]: time="2026-10-12T19:59:50+02:00" level=debug msg="obtained new client token: AAFqNuHiNUeKE6BFgtqFm4ZIf6rXgQcY2xM2utHN44YfmLud8YhKEZ9QmFZaod6GjORyMQ0EXjPYm1bVn8x2HL0JqPBGicI08u0pyWJ4k0ybCYXRSDCe3DQ9ReQ/PTGt6Y+jMU7B6PgLU2yFcOZ5Vh3PTJsGp6yPVm0b6OxVnEncCxVy+mSv98Yei0oOwZ4/LwT1zmlOXSHkby7NoSNUBkPnCUv5zE5hFnY7rf98vMQk6vsMHeSEnSU=" Oct 12 19:59:50 bcik go-librespot[3426]: time="2026-10-12T19:59:50+02: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" Oct 12 19:59:50 bcik go-librespot[3426]: time="2026-10-12T19:59:50+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Oct 12 19:59:50 bcik go-librespot[3426]: time="2026-10-12T19:59:50+02:00" level=debug msg="completed keyexchange" Oct 12 19:59:50 bcik go-librespot[3426]: time="2026-10-12T19:59:50+02:00" level=debug msg="completed challenge" Oct 12 19:59:50 bcik go-librespot[3426]: time="2026-10-12T19:59:50+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 19:59:50 bcik go-librespot[3426]: time="2026-10-12T19:59:50+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 19:59:50 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 19:59:50 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 19:59:51 bcik volumio[2899]: info: Initializing connection to go-librespot Websocket Oct 12 19:59:51 bcik volumio[2899]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 19:59:54 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 94. Oct 12 19:59:54 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:59:54 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 19:59:54 bcik go-librespot[3449]: go-librespot daemon starting... Oct 12 19:59:54 bcik go-librespot[3450]: time="2026-10-12T19:59:54+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 19:59:54 bcik go-librespot[3450]: time="2026-10-12T19:59:54+02:00" level=debug msg="app state loaded" Oct 12 19:59:54 bcik go-librespot[3450]: time="2026-10-12T19:59:54+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 19:59:54 bcik go-librespot[3450]: time="2026-10-12T19:59:54+02: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]" Oct 12 19:59:54 bcik go-librespot[3450]: time="2026-10-12T19:59:54+02: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]" Oct 12 19:59:54 bcik go-librespot[3450]: time="2026-10-12T19:59:54+02: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]" Oct 12 19:59:54 bcik go-librespot[3450]: time="2026-10-12T19:59:54+02:00" level=info msg="zeroconf server listening on port 45909" Oct 12 19:59:54 bcik volumio[2899]: info: Initializing connection to go-librespot Websocket Oct 12 19:59:54 bcik go-librespot[3450]: time="2026-10-12T19:59:54+02:00" level=debug msg="new websocket client" Oct 12 19:59:54 bcik volumio[2899]: info: Connection to go-librespot Websocket established Oct 12 19:59:57 bcik volumio[2899]: info: Getting Spotify volume Oct 12 19:59:57 bcik volumio[2899]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Oct 12 19:59:57 bcik volumio[2899]: info: CoreCommandRouter::volumioGetState Oct 12 19:59:57 bcik volumio[2899]: info: CorePlayQueue::getTrack 0 Oct 12 19:59:57 bcik volumio[2899]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 Oct 12 19:59:57 bcik volumio[2899]: SPOTIFY: SPOTIFY VOLUME undefined Oct 12 19:59:57 bcik volumio[2899]: SPOTIFY: VOLUMIO VOLUME 41 Oct 12 19:59:57 bcik volumio[2899]: info: Aligning Spotify Volume to Volumio Volume Oct 12 19:59:57 bcik volumio[2899]: info: CoreCommandRouter::volumioGetState Oct 12 19:59:57 bcik volumio[2899]: info: CorePlayQueue::getTrack 0 Oct 12 19:59:57 bcik volumio[2899]: info: Setting Spotify Volume from Volumio: 41 Oct 12 19:59:59 bcik volumio[2899]: SPOTIFY: SETTING SPOTIFY VOLUME 41 Oct 12 19:59:59 bcik volumio[2899]: info: Sending Spotify command with payload to local API: /player/volume Oct 12 19:59:59 bcik go-librespot[3450]: time="2026-10-12T19:59:59+02:00" level=debug msg="obtained new client token: AAFYIl7x56oZnVbgHBPgnbb8y0sX3cKMHHMJQZ7LLpIX/cJDLI5x8QgUoSEFAcoyJBOa94RdDCUwaPN4S6sh/U3LZ5had1FkQGoOKQLIj/cTJKkwyg6zttEd158/A18je7gpfJpNm9STU0NSjYkF9DsRs9/rkGcpWlS2c+8ddl3rnh9ozyyaJ7J+aiFGNmT606aZPBgjZKE4iiyKCjasgYWB1qqd5SFKEnziYeZqiTbhhL2/zFtd" Oct 12 19:59:59 bcik go-librespot[3450]: time="2026-10-12T19:59:59+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 19:59:59 bcik go-librespot[3450]: time="2026-10-12T19:59:59+02:00" level=debug msg="completed keyexchange" Oct 12 19:59:59 bcik go-librespot[3450]: time="2026-10-12T19:59:59+02:00" level=debug msg="completed challenge" Oct 12 19:59:59 bcik go-librespot[3450]: time="2026-10-12T19:59:59+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 19:59:59 bcik go-librespot[3450]: time="2026-10-12T19:59:59+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 19:59:59 bcik volumio[2899]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Oct 12 19:59:59 bcik volumio[2899]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 19:59:59 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 19:59:59 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 19:59:59 bcik volumio[2899]: Error: socket hang up Oct 12 19:59:59 bcik volumio[2899]: at connResetException (node:internal/errors:720:14) Oct 12 19:59:59 bcik volumio[2899]: at Socket.socketOnEnd (node:_http_client:519:23) Oct 12 19:59:59 bcik volumio[2899]: at Socket.emit (node:events:526:35) Oct 12 19:59:59 bcik volumio[2899]: at endReadableNT (node:internal/streams/readable:1376:12) Oct 12 19:59:59 bcik volumio[2899]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Oct 12 19:59:59 bcik volumio[2899]: code: 'ECONNRESET', Oct 12 19:59:59 bcik volumio[2899]: response: undefined Oct 12 19:59:59 bcik volumio[2899]: } Oct 12 19:59:59 bcik volumio[2899]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 19:59:59 bcik sudo[3473]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-12 19:58' Oct 12 19:59:59 bcik sudo[3473]: 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="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"