Aug 31 15:26:01 bcik volumio-remote-updater[962]: [2026-08-31 15:26:01] [connect] Successful connection Aug 31 15:26:01 bcik volumio-remote-updater[962]: [2026-08-31 15:26:01] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1788182761 101 Aug 31 15:26:01 bcik volumio[2154]: 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 Aug 31 15:26:01 bcik volumio[2154]: info: go-librespot daemon successfully initialized Aug 31 15:26:02 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 268. Aug 31 15:26:02 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:26:02 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:26:02 bcik go-librespot[2390]: go-librespot daemon starting... Aug 31 15:26:02 bcik go-librespot[2391]: time="2026-08-31T15:26:02+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:26:02 bcik go-librespot[2391]: time="2026-08-31T15:26:02+02:00" level=debug msg="app state loaded" Aug 31 15:26:02 bcik go-librespot[2391]: time="2026-08-31T15:26:02+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:26:02 bcik go-librespot[2391]: time="2026-08-31T15:26:02+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]" Aug 31 15:26:02 bcik go-librespot[2391]: time="2026-08-31T15:26:02+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]" Aug 31 15:26:02 bcik go-librespot[2391]: time="2026-08-31T15:26:02+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]" Aug 31 15:26:02 bcik go-librespot[2391]: time="2026-08-31T15:26:02+02:00" level=info msg="zeroconf server listening on port 37169" Aug 31 15:26:02 bcik go-librespot[2391]: time="2026-08-31T15:26:02+02:00" level=debug msg="obtained new client token: AAG6m67Aq6/QrOHQY9mzYx/HqrT/L+7agfmp+a6rduRQpBkueXIVpvl7thn56smzjSW62TN1i78eZCVDQwQ+eyWS+9mYEBqSSTWIc8b0IGq2E/uRwCSOkS66+pSkW0zX721A//t/AQtxS6FcyEY9j3MN+JSz4xher0nOyWCxteIMiIKqJ5yhhf8I9UOHPhNqyx4Jl3WJar7gL7DPoEbtR7d+uerZOU6+JF4ksD6fyJdHZdj5z3npV0I=" Aug 31 15:26:02 bcik go-librespot[2391]: time="2026-08-31T15:26:02+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:26:02 bcik go-librespot[2391]: time="2026-08-31T15:26:02+02:00" level=debug msg="completed keyexchange" Aug 31 15:26:02 bcik go-librespot[2391]: time="2026-08-31T15:26:02+02:00" level=debug msg="completed challenge" Aug 31 15:26:02 bcik go-librespot[2391]: time="2026-08-31T15:26:02+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:26:02 bcik go-librespot[2391]: time="2026-08-31T15:26:02+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:26:02 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:26:02 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:26:04 bcik volumio[2154]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Aug 31 15:26:04 bcik volumio[2154]: info: Initializing connection to go-librespot Websocket Aug 31 15:26:04 bcik volumio[2154]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:26:05 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 269. Aug 31 15:26:05 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:26:05 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:26:05 bcik go-librespot[2401]: go-librespot daemon starting... Aug 31 15:26:05 bcik go-librespot[2402]: time="2026-08-31T15:26:05+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:26:05 bcik go-librespot[2402]: time="2026-08-31T15:26:05+02:00" level=debug msg="app state loaded" Aug 31 15:26:05 bcik go-librespot[2402]: time="2026-08-31T15:26:05+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:26:05 bcik go-librespot[2402]: time="2026-08-31T15:26: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 15:26:05 bcik go-librespot[2402]: time="2026-08-31T15:26:05+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]" Aug 31 15:26:05 bcik go-librespot[2402]: time="2026-08-31T15:26:05+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]" Aug 31 15:26:05 bcik go-librespot[2402]: time="2026-08-31T15:26:05+02:00" level=info msg="zeroconf server listening on port 40735" Aug 31 15:26:06 bcik go-librespot[2402]: time="2026-08-31T15:26:06+02:00" level=debug msg="obtained new client token: AAFprE11s8agr4fpsA3VYxGwvHKNY569dikbTq2Sr7EIDOOS1MZYjTRqX/nCE2Vc68oYQPdQo4YOMlYMuHujIrx2K08nEMl0lJ9qxd5iiVBo1YctADugd6thBKTfssDsN0ZrVjUqiR0fHVsTj7SwptffXjKfxItHLWDhlYPvnava2OifXbnAc7gFX4TLCAcqxj2f1EHIc2M1rRG/aCEwXYfXW5Snazt0rfU4ZNgNFye0A3i2QjrtmIY=" Aug 31 15:26:06 bcik go-librespot[2402]: time="2026-08-31T15:26:06+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:26:06 bcik go-librespot[2402]: time="2026-08-31T15:26:06+02:00" level=debug msg="completed keyexchange" Aug 31 15:26:06 bcik go-librespot[2402]: time="2026-08-31T15:26:06+02:00" level=debug msg="completed challenge" Aug 31 15:26:06 bcik go-librespot[2402]: time="2026-08-31T15:26:06+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:26:06 bcik go-librespot[2402]: time="2026-08-31T15:26:06+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:26:06 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:26:06 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:26:07 bcik volumio[2154]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Aug 31 15:26:07 bcik volumio[2154]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Aug 31 15:26:07 bcik volumio[2154]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Aug 31 15:26:07 bcik volumio[2154]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Aug 31 15:26:07 bcik volumio[2154]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Aug 31 15:26:07 bcik volumio[2154]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Aug 31 15:26:07 bcik volumio[2154]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Aug 31 15:26:07 bcik volumio[2154]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Aug 31 15:26:07 bcik volumio[2154]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Aug 31 15:26:07 bcik volumio[2154]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Aug 31 15:26:07 bcik volumio[2154]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Aug 31 15:26:07 bcik volumio[2154]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Aug 31 15:26:07 bcik volumio[2154]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Aug 31 15:26:07 bcik volumio[2154]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Aug 31 15:26:07 bcik volumio[2154]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Aug 31 15:26:07 bcik volumio[2154]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Aug 31 15:26:07 bcik volumio[2154]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Aug 31 15:26:07 bcik volumio[2154]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Aug 31 15:26:07 bcik volumio[2154]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Aug 31 15:26:07 bcik volumio[2154]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Aug 31 15:26:07 bcik volumio[2154]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Aug 31 15:26:07 bcik volumio[2154]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Aug 31 15:26:07 bcik volumio[2154]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Aug 31 15:26:07 bcik volumio[2154]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Aug 31 15:26:07 bcik volumio[2154]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Aug 31 15:26:07 bcik volumio[2154]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Aug 31 15:26:07 bcik volumio[2154]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Aug 31 15:26:07 bcik volumio[2154]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Aug 31 15:26:07 bcik volumio[2154]: info: Adding plugin bluetooth to MyMusic Plugins Aug 31 15:26:07 bcik volumio[2154]: info: Adding plugin multiroom to MyMusic Plugins Aug 31 15:26:07 bcik volumio[2154]: info: Adding plugin metavolumio to MyMusic Plugins Aug 31 15:26:07 bcik volumio[2154]: info: Adding plugin cd_controller to MyMusic Plugins Aug 31 15:26:07 bcik volumio[2154]: info: Adding plugin qobuzconnect to MyMusic Plugins Aug 31 15:26:07 bcik volumio[2154]: info: Adding plugin smart_inputs to MyMusic Plugins Aug 31 15:26:07 bcik volumio[2154]: info: Adding plugin tidalconnect to MyMusic Plugins Aug 31 15:26:07 bcik volumio[2154]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Aug 31 15:26:07 bcik volumio[2154]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Aug 31 15:26:07 bcik volumio[2154]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Aug 31 15:26:07 bcik volumio[2154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:26:07 bcik volumio[2154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:26:07 bcik volumio[2154]: info: Starting MyVolumio Remote Streaming Endpoints Aug 31 15:26:07 bcik volumio[2154]: info: MyVolumio login type: Token Aug 31 15:26:07 bcik volumio[2154]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Aug 31 15:26:07 bcik volumio[2154]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Aug 31 15:26:07 bcik volumio[2154]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Aug 31 15:26:07 bcik volumio[2154]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Aug 31 15:26:07 bcik volumio[2154]: info: Streaming services startup Aug 31 15:26:07 bcik volumio[2154]: info: Starting Streaming Daemon Aug 31 15:26:07 bcik sudo[2426]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 31 15:26:07 bcik sudo[2426]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:26:07 bcik volumio[2154]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Aug 31 15:26:07 bcik sudo[2426]: pam_unix(sudo:session): session closed for user root Aug 31 15:26:07 bcik volumio[2154]: info: Initializing connection to go-librespot Websocket Aug 31 15:26:07 bcik sudo[2433]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 31 15:26:07 bcik sudo[2433]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:26:07 bcik sudo[2433]: pam_unix(sudo:session): session closed for user root Aug 31 15:26:07 bcik sudo[2435]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 31 15:26:07 bcik sudo[2435]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:26:07 bcik sudo[2435]: pam_unix(sudo:session): session closed for user root Aug 31 15:26:07 bcik volumio[2154]: error: Cannot start Volumio Streaming Daemon Aug 31 15:26:07 bcik volumio[2154]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 31 15:26:07 bcik volumio[2154]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 31 15:26:07 bcik volumio[2154]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:26:07 bcik sudo[2439]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Aug 31 15:26:07 bcik sudo[2439]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:26:07 bcik sudo[2439]: pam_unix(sudo:session): session closed for user root Aug 31 15:26:07 bcik volumio[2154]: info: Upmpdcli Daemon Started Aug 31 15:26:08 bcik volumio[2154]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Aug 31 15:26:08 bcik volumio[2154]: info: MyVolumio token set successfully Aug 31 15:26:08 bcik volumio[2154]: info: MYVOLUMIO: Adding device Aug 31 15:26:08 bcik volumio[2154]: info: MYVOLUMIO: Evaluating Server Aug 31 15:26:08 bcik volumio[2154]: info: MyVolumio status changed Aug 31 15:26:08 bcik volumio[2154]: info: Streaming services startup Aug 31 15:26:08 bcik volumio[2154]: info: Starting Streaming Daemon Aug 31 15:26:08 bcik volumio[2154]: info: Removing browser output: myVolumio user plan is not superstar Aug 31 15:26:08 bcik volumio[2154]: info: Removing audio output: Aug 31 15:26:08 bcik volumio[2154]: info: Stoppping Tunnel 1 Aug 31 15:26:08 bcik sudo[2463]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 31 15:26:08 bcik sudo[2463]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:26:08 bcik sudo[2463]: pam_unix(sudo:session): session closed for user root Aug 31 15:26:08 bcik volumio[2154]: error: Cannot start Volumio Streaming Daemon Aug 31 15:26:08 bcik volumio[2154]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 31 15:26:08 bcik volumio[2154]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 31 15:26:08 bcik sudo[2466]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Aug 31 15:26:08 bcik sudo[2466]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:26:08 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. Aug 31 15:26:08 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. Aug 31 15:26:08 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. Aug 31 15:26:08 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. Aug 31 15:26:08 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. Aug 31 15:26:08 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. Aug 31 15:26:08 bcik sudo[2466]: pam_unix(sudo:session): session closed for user root Aug 31 15:26:08 bcik volumio[2154]: info: Remote SSH Stopped Aug 31 15:26:08 bcik volumio[2154]: info: Setting Geolocation for MyVolumio to eu6 Aug 31 15:26:08 bcik volumio[2154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:26:08 bcik volumio[2154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:26:08 bcik volumio[2154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:26:09 bcik volumio[2154]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Aug 31 15:26:09 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 270. Aug 31 15:26:09 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:26:09 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:26:09 bcik go-librespot[2468]: go-librespot daemon starting... Aug 31 15:26:09 bcik go-librespot[2469]: time="2026-08-31T15:26:09+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:26:09 bcik go-librespot[2469]: time="2026-08-31T15:26:09+02:00" level=debug msg="app state loaded" Aug 31 15:26:09 bcik go-librespot[2469]: time="2026-08-31T15:26:09+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:26:09 bcik go-librespot[2469]: time="2026-08-31T15:26:09+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]" Aug 31 15:26:09 bcik go-librespot[2469]: time="2026-08-31T15:26:09+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]" Aug 31 15:26:09 bcik go-librespot[2469]: time="2026-08-31T15:26:09+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]" Aug 31 15:26:09 bcik go-librespot[2469]: time="2026-08-31T15:26:09+02:00" level=info msg="zeroconf server listening on port 44653" Aug 31 15:26:09 bcik go-librespot[2469]: time="2026-08-31T15:26:09+02:00" level=debug msg="obtained new client token: AAHrd0oDj6tiepU/QxNIQ1DKMAzYVeJaho8IOAWx7YV8eGTJDocdoyjl7j7VdERhRPF2mLLVVPSnMlh7xdkUERX5ajgg4tUA3C1A1hH4fUCVRAc1V7y+RIO9cTPGHrJXvwo7xD8JOIj56BFbdbicGZTEmky8ihtnNECD1pLsw7j4H3Y3NWwtQXywGX36+zcFuJMZqo9FYkomL/+HZxDiWxoh+he3R9EDVss47CYodSC6fuzLj24ahkM=" Aug 31 15:26:09 bcik go-librespot[2469]: time="2026-08-31T15:26:09+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:26:09 bcik go-librespot[2469]: time="2026-08-31T15:26:09+02:00" level=debug msg="completed keyexchange" Aug 31 15:26:09 bcik go-librespot[2469]: time="2026-08-31T15:26:09+02:00" level=debug msg="completed challenge" Aug 31 15:26:09 bcik go-librespot[2469]: time="2026-08-31T15:26:09+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:26:09 bcik go-librespot[2469]: time="2026-08-31T15:26:09+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:26:09 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:26:09 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:26:09 bcik volumio[2154]: info: Updating MyVolumio device info Aug 31 15:26:09 bcik volumio[2154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:26:09 bcik volumio[2154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:26:09 bcik volumio[2154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:26:10 bcik volumio[2154]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Aug 31 15:26:10 bcik volumio[2154]: info: Initializing connection to go-librespot Websocket Aug 31 15:26:10 bcik volumio[2154]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:26:12 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 271. Aug 31 15:26:12 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:26:12 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:26:12 bcik go-librespot[2478]: go-librespot daemon starting... Aug 31 15:26:12 bcik go-librespot[2479]: time="2026-08-31T15:26:12+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:26:12 bcik go-librespot[2479]: time="2026-08-31T15:26:12+02:00" level=debug msg="app state loaded" Aug 31 15:26:12 bcik go-librespot[2479]: time="2026-08-31T15:26:12+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:26:12 bcik go-librespot[2479]: time="2026-08-31T15:26: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]" Aug 31 15:26:12 bcik go-librespot[2479]: time="2026-08-31T15:26: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]" Aug 31 15:26:12 bcik go-librespot[2479]: time="2026-08-31T15:26: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]" Aug 31 15:26:12 bcik go-librespot[2479]: time="2026-08-31T15:26:12+02:00" level=info msg="zeroconf server listening on port 42055" Aug 31 15:26:12 bcik go-librespot[2479]: time="2026-08-31T15:26:12+02:00" level=debug msg="obtained new client token: AAHPvpWI8d+zKA5yDzM7eheUELEPArtkDGzs/jThdS3QEy0jpYYjhSaAoY68yGtgApkghe6HfnjspzrmHB8Afqe2CG6+B5h/EYw6XVvUx/wB7oJU34tEjU/Y4DLRDLsyguf3m9DpGL/2vpItLKdUATGnEPOwTaq5+lESx4T+M4Jvl1X+HhMbjIQrYyYwuXu4e601+XKRQy+QNRPGYe9pW9eKJCwURmHIQrvKzmvMgd+9OJsnGhpEY+s=" Aug 31 15:26:12 bcik go-librespot[2479]: time="2026-08-31T15:26:12+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:26:13 bcik go-librespot[2479]: time="2026-08-31T15:26:13+02:00" level=debug msg="completed keyexchange" Aug 31 15:26:13 bcik go-librespot[2479]: time="2026-08-31T15:26:13+02:00" level=debug msg="completed challenge" Aug 31 15:26:13 bcik go-librespot[2479]: time="2026-08-31T15:26:13+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:26:13 bcik go-librespot[2479]: time="2026-08-31T15:26:13+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:26:13 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:26:13 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:26:13 bcik volumio[2154]: info: MYVOLUMIO: Adding device Aug 31 15:26:13 bcik volumio[2154]: info: MYVOLUMIO: Evaluating Server Aug 31 15:26:13 bcik volumio[2154]: info: Initializing connection to go-librespot Websocket Aug 31 15:26:13 bcik volumio[2154]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:26:13 bcik volumio[2154]: info: Setting Geolocation for MyVolumio to eu6 Aug 31 15:26:13 bcik volumio[2154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:26:13 bcik volumio[2154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:26:13 bcik volumio[2154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:26:13 bcik volumio[2154]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Aug 31 15:26:14 bcik volumio[2154]: info: Updating MyVolumio device info Aug 31 15:26:14 bcik volumio[2154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:26:14 bcik volumio[2154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:26:14 bcik volumio[2154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:26:14 bcik volumio[2154]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Aug 31 15:26:16 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 272. Aug 31 15:26:16 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:26:16 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:26:16 bcik go-librespot[2506]: go-librespot daemon starting... Aug 31 15:26:16 bcik go-librespot[2507]: time="2026-08-31T15:26:16+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:26:16 bcik go-librespot[2507]: time="2026-08-31T15:26:16+02:00" level=debug msg="app state loaded" Aug 31 15:26:16 bcik go-librespot[2507]: time="2026-08-31T15:26:16+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:26:16 bcik go-librespot[2507]: time="2026-08-31T15:26:16+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]" Aug 31 15:26:16 bcik go-librespot[2507]: time="2026-08-31T15:26:16+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]" Aug 31 15:26:16 bcik go-librespot[2507]: time="2026-08-31T15:26:16+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]" Aug 31 15:26:16 bcik go-librespot[2507]: time="2026-08-31T15:26:16+02:00" level=info msg="zeroconf server listening on port 43899" Aug 31 15:26:16 bcik go-librespot[2507]: time="2026-08-31T15:26:16+02:00" level=debug msg="obtained new client token: AAGkwG3alAQSxVv+tHKilOfJIU+gER5iPfTQHKVBOcXfVWb4DVn7KWr6DFzeVlBjPoMkUrEYpCYVrxLg2UJIqjtpiAmpasrBn7iWnQNEtdB8Ukr/kYKkl5UpKDDIg4327zIGHHoBcK9+CUqK3aPWTjXsFZXtMrZUoxjVwT5ecYggkF/TJ6SYoHSA8ieo/tPWWaOZQTyhW2hl2W5id70fPkSFOAhBBOqaqZ8Q4OjWQHg/wuNyCjGYeUI=" Aug 31 15:26:16 bcik go-librespot[2507]: time="2026-08-31T15:26:16+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:26:16 bcik go-librespot[2507]: time="2026-08-31T15:26:16+02:00" level=debug msg="completed keyexchange" Aug 31 15:26:16 bcik go-librespot[2507]: time="2026-08-31T15:26:16+02:00" level=debug msg="completed challenge" Aug 31 15:26:16 bcik go-librespot[2507]: time="2026-08-31T15:26:16+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:26:16 bcik go-librespot[2507]: time="2026-08-31T15:26:16+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:26:16 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:26:16 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:26:16 bcik volumio[2154]: info: Initializing connection to go-librespot Websocket Aug 31 15:26:16 bcik volumio[2154]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:26:19 bcik volumio[2154]: info: Initializing connection to go-librespot Websocket Aug 31 15:26:19 bcik volumio[2154]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:26:19 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 273. Aug 31 15:26:19 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:26:19 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:26:19 bcik go-librespot[2530]: go-librespot daemon starting... Aug 31 15:26:19 bcik go-librespot[2531]: time="2026-08-31T15:26:19+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:26:19 bcik go-librespot[2531]: time="2026-08-31T15:26:19+02:00" level=debug msg="app state loaded" Aug 31 15:26:19 bcik go-librespot[2531]: time="2026-08-31T15:26:19+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:26:19 bcik go-librespot[2531]: time="2026-08-31T15:26: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]" Aug 31 15:26:19 bcik go-librespot[2531]: time="2026-08-31T15:26: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]" Aug 31 15:26:19 bcik go-librespot[2531]: time="2026-08-31T15:26: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]" Aug 31 15:26:19 bcik go-librespot[2531]: time="2026-08-31T15:26:19+02:00" level=info msg="zeroconf server listening on port 40631" Aug 31 15:26:19 bcik go-librespot[2531]: time="2026-08-31T15:26:19+02:00" level=debug msg="obtained new client token: AAGcJDtzvTrA9ftXMZ76p3VlmOWKHPTv4GVOHXUVCFGiMAy+anng8+B5U2l9gH1K0qnr8IuAbnqk5b94CB35OKSrvfvURPGp6pt/iwDJDYfEByGTxw5HUtUBlUeJ2DhwbixdxGYWrkH2FLRQNPoIY6BKVhATr9WiRMAm2Dk2x9Ulqbpv+O2g9LYwBQ9AhdiU5Cw6Rz3cv0ANRLeSqYHnF5KKSIfX+XmJpq3NiJSMKnRe5tMcFdb1F7U=" Aug 31 15:26:19 bcik go-librespot[2531]: time="2026-08-31T15:26:19+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:26:20 bcik go-librespot[2531]: time="2026-08-31T15:26:20+02:00" level=debug msg="completed keyexchange" Aug 31 15:26:20 bcik go-librespot[2531]: time="2026-08-31T15:26:20+02:00" level=debug msg="completed challenge" Aug 31 15:26:20 bcik go-librespot[2531]: time="2026-08-31T15:26:20+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:26:20 bcik go-librespot[2531]: time="2026-08-31T15:26:20+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:26:20 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:26:20 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:26:22 bcik volumio[2154]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 31 15:26:22 bcik volumio[2154]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Aug 31 15:26:22 bcik volumio[2154]: info: CoreCommandRouter::volumioGetState Aug 31 15:26:22 bcik volumio[2154]: info: CorePlayQueue::getTrack 0 Aug 31 15:26:22 bcik volumio[2154]: info: Initializing connection to go-librespot Websocket Aug 31 15:26:22 bcik volumio[2154]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:26:23 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 274. Aug 31 15:26:23 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:26:23 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:26:23 bcik go-librespot[2540]: go-librespot daemon starting... Aug 31 15:26:23 bcik go-librespot[2541]: time="2026-08-31T15:26:23+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:26:23 bcik go-librespot[2541]: time="2026-08-31T15:26:23+02:00" level=debug msg="app state loaded" Aug 31 15:26:23 bcik go-librespot[2541]: time="2026-08-31T15:26:23+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:26:23 bcik go-librespot[2541]: time="2026-08-31T15:26:23+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]" Aug 31 15:26:23 bcik go-librespot[2541]: time="2026-08-31T15:26:23+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]" Aug 31 15:26:23 bcik go-librespot[2541]: time="2026-08-31T15:26:23+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]" Aug 31 15:26:23 bcik go-librespot[2541]: time="2026-08-31T15:26:23+02:00" level=info msg="zeroconf server listening on port 34423" Aug 31 15:26:23 bcik go-librespot[2541]: time="2026-08-31T15:26:23+02:00" level=debug msg="obtained new client token: AAEXMe3P9Mm/eqqe+vUOHac0YPdTOvZcOcDJT+f4j8cf5SB81HjBEJZDOTUOtKJyIcG8N6dnv303YMPSxlUHGn0xu9WR2O9S7RrHFOM5tZfECXBAHSC3DoVIXZhuvHtiyzKNSTTbl2SeNRqKqUI+7CN6HQe+1kvEJiPGsyLeD/6kb72OF+ozTxYmHQbZWZq8NJT+BmFte1lvn5+6l4SDLlDKQGOHCOdKNkPoZHbHm2L8H5SKN7oCkgs=" Aug 31 15:26:23 bcik go-librespot[2541]: time="2026-08-31T15:26:23+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:26:23 bcik go-librespot[2541]: time="2026-08-31T15:26:23+02:00" level=debug msg="completed keyexchange" Aug 31 15:26:23 bcik go-librespot[2541]: time="2026-08-31T15:26:23+02:00" level=debug msg="completed challenge" Aug 31 15:26:23 bcik go-librespot[2541]: time="2026-08-31T15:26:23+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:26:23 bcik go-librespot[2541]: time="2026-08-31T15:26:23+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:26:23 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:26:23 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:26:25 bcik volumio[2154]: info: Initializing connection to go-librespot Websocket Aug 31 15:26:25 bcik volumio[2154]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:26:26 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 275. Aug 31 15:26:26 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:26:26 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:26:26 bcik go-librespot[2551]: go-librespot daemon starting... Aug 31 15:26:26 bcik go-librespot[2552]: time="2026-08-31T15:26:26+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:26:26 bcik go-librespot[2552]: time="2026-08-31T15:26:26+02:00" level=debug msg="app state loaded" Aug 31 15:26:26 bcik go-librespot[2552]: time="2026-08-31T15:26:26+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:26:26 bcik go-librespot[2552]: time="2026-08-31T15:26: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-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 15:26:26 bcik go-librespot[2552]: time="2026-08-31T15:26:26+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]" Aug 31 15:26:26 bcik go-librespot[2552]: time="2026-08-31T15:26:26+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]" Aug 31 15:26:26 bcik go-librespot[2552]: time="2026-08-31T15:26:26+02:00" level=info msg="zeroconf server listening on port 41897" Aug 31 15:26:26 bcik go-librespot[2552]: time="2026-08-31T15:26:26+02:00" level=debug msg="obtained new client token: AAHXriEZfMeCtkw6NeEbeWNLwUD+JUto2OwdXPx6vCUKVa5kHe1IGc1WJIoSmnultt7aFXaen9aKNejF+szrXnoBiQ6k4jxzw+V1r59ej9uBix2cs8MVYa4/rq7iHpq9MXWqr6Dw6HXfkCF0VRZnt81P4H4R4Praku6lh9q7PxJ9k48AwK+YbkFM5LZ3nZBlvV7LoTkhBu8byRRs7HlpEiBku/Zp/cXMnpUT/RTvcCLj9k27TENJe8Q=" Aug 31 15:26:26 bcik go-librespot[2552]: time="2026-08-31T15:26:26+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:26:27 bcik go-librespot[2552]: time="2026-08-31T15:26:27+02:00" level=debug msg="completed keyexchange" Aug 31 15:26:27 bcik go-librespot[2552]: time="2026-08-31T15:26:27+02:00" level=debug msg="completed challenge" Aug 31 15:26:27 bcik go-librespot[2552]: time="2026-08-31T15:26:27+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:26:27 bcik go-librespot[2552]: time="2026-08-31T15:26:27+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:26:27 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:26:27 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:26:27 bcik volumio[2154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:26:27 bcik volumio[2154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:26:27 bcik volumio[2154]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Aug 31 15:26:27 bcik volumio[2154]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Aug 31 15:26:27 bcik volumio[2154]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Aug 31 15:26:27 bcik volumio[2154]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Aug 31 15:26:27 bcik volumio[2154]: info: CoreCommandRouter::volumioGetBrowseSources Aug 31 15:26:27 bcik volumio[2154]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 15:26:27 bcik volumio[2154]: error: MyVolumio Plugin failed to authenticate in a timely fashion Aug 31 15:26:27 bcik volumio[2154]: info: Completed starting MyVolumio Plugin Aug 31 15:26:27 bcik volumio[2154]: [Metrics] CommandRouter: 30s 666.82ms Aug 31 15:26:27 bcik volumio[2154]: info: CoreCommandRouter::volumiosetStartupVolume Aug 31 15:26:27 bcik volumio[2154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:26:27 bcik volumio[2154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:26:27 bcik volumio[2154]: info: CoreCommandRouter::Close All Modals sent Aug 31 15:26:27 bcik volumio[2154]: info: CoreCommandRouter::Close All Modals sent Aug 31 15:26:28 bcik volumio[2154]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 15:26:28 bcik volumio[2154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:26:28 bcik volumio[2154]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 31 15:26:28 bcik volumio-remote-updater[962]: Test mode disabled Aug 31 15:26:28 bcik volumio-remote-updater[962]: Alpha mode disabled Aug 31 15:26:28 bcik volumio-remote-updater[962]: Alpha legacy test mode disabled Aug 31 15:26:28 bcik volumio[2154]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Aug 31 15:26:28 bcik volumio[2154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Aug 31 15:26:28 bcik volumio[2154]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 31 15:26:28 bcik volumio[2154]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Aug 31 15:26:28 bcik volumio[2154]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Aug 31 15:26:28 bcik volumio[2154]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Aug 31 15:26:28 bcik volumio[2154]: info: Initializing connection to go-librespot Websocket Aug 31 15:26:28 bcik volumio[2154]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:26:30 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 276. Aug 31 15:26:30 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:26:30 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:26:30 bcik go-librespot[2581]: go-librespot daemon starting... Aug 31 15:26:30 bcik go-librespot[2582]: time="2026-08-31T15:26:30+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:26:30 bcik go-librespot[2582]: time="2026-08-31T15:26:30+02:00" level=debug msg="app state loaded" Aug 31 15:26:30 bcik go-librespot[2582]: time="2026-08-31T15:26:30+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:26:30 bcik go-librespot[2582]: time="2026-08-31T15:26:30+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]" Aug 31 15:26:30 bcik go-librespot[2582]: time="2026-08-31T15:26:30+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]" Aug 31 15:26:30 bcik go-librespot[2582]: time="2026-08-31T15:26:30+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]" Aug 31 15:26:30 bcik go-librespot[2582]: time="2026-08-31T15:26:30+02:00" level=info msg="zeroconf server listening on port 33823" Aug 31 15:26:30 bcik go-librespot[2582]: time="2026-08-31T15:26:30+02:00" level=debug msg="obtained new client token: AAGTKNDdF94mPvIJQ00AuXUCWja/9fjqhulV2PvQPb5bUa8sM/6JHgitQ0pQ5yON1C/8x5y+Vg+WXVOFty/ZLrKI+MpQWzplsiMnlCxWlTY/dpQRSI01+xZASmiBRYBOMppSPFzlUICc7biSam0EEfKw3wl8z4/4nBsUaVtfwWf6ock4szcYDH2iww0u7t0VnEQhG7anA65FPrzAt3ytbaSxIaJANJearqh46gkyEhGWDQKH03U1Iac=" Aug 31 15:26:30 bcik go-librespot[2582]: time="2026-08-31T15:26:30+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:26:30 bcik go-librespot[2582]: time="2026-08-31T15:26:30+02:00" level=debug msg="completed keyexchange" Aug 31 15:26:30 bcik go-librespot[2582]: time="2026-08-31T15:26:30+02:00" level=debug msg="completed challenge" Aug 31 15:26:30 bcik go-librespot[2582]: time="2026-08-31T15:26:30+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:26:30 bcik go-librespot[2582]: time="2026-08-31T15:26:30+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:26:30 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:26:30 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:26:31 bcik volumio[2154]: info: Initializing connection to go-librespot Websocket Aug 31 15:26:31 bcik volumio[2154]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:26:33 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 277. Aug 31 15:26:33 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:26:33 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:26:33 bcik go-librespot[2591]: go-librespot daemon starting... Aug 31 15:26:33 bcik go-librespot[2592]: time="2026-08-31T15:26:33+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:26:33 bcik go-librespot[2592]: time="2026-08-31T15:26:33+02:00" level=debug msg="app state loaded" Aug 31 15:26:33 bcik go-librespot[2592]: time="2026-08-31T15:26:33+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:26:33 bcik go-librespot[2592]: time="2026-08-31T15:26: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]" Aug 31 15:26:33 bcik go-librespot[2592]: time="2026-08-31T15:26: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]" Aug 31 15:26:33 bcik go-librespot[2592]: time="2026-08-31T15:26: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]" Aug 31 15:26:33 bcik go-librespot[2592]: time="2026-08-31T15:26:33+02:00" level=info msg="zeroconf server listening on port 41877" Aug 31 15:26:33 bcik go-librespot[2592]: time="2026-08-31T15:26:33+02:00" level=debug msg="obtained new client token: AAFX4s1SidO6KGEf2DFOspxs5I3ru256HXPxhLnCH+lgYBRqCFUgaxRplI0Gvf06MyC5XMXck0M2ltyAY1Em+CPw6fsX2xOLqur+C4VojYSpBKy2OpKC10nMq+/EVohdzWkLhO0iJDZIZiV+iDEA9aJvIkijDFevLgRB9C2U1zzYjpa3/EgscUYQxiqFXUnPDRckT5wl13k5fyfSOQWCO+ncSMHie/l1po2zrnZaxssEbkPZW/y21HE=" Aug 31 15:26:33 bcik go-librespot[2592]: time="2026-08-31T15:26:33+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:26:34 bcik go-librespot[2592]: time="2026-08-31T15:26:34+02:00" level=debug msg="completed keyexchange" Aug 31 15:26:34 bcik go-librespot[2592]: time="2026-08-31T15:26:34+02:00" level=debug msg="completed challenge" Aug 31 15:26:34 bcik go-librespot[2592]: time="2026-08-31T15:26:34+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:26:34 bcik go-librespot[2592]: time="2026-08-31T15:26:34+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:26:34 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:26:34 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:26:34 bcik volumio[2154]: info: BOOT COMPLETED Aug 31 15:26:34 bcik volumio[2154]: info: Initializing connection to go-librespot Websocket Aug 31 15:26:34 bcik volumio[2154]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:26:37 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 278. Aug 31 15:26:37 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:26:37 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:26:37 bcik go-librespot[2601]: go-librespot daemon starting... Aug 31 15:26:37 bcik go-librespot[2602]: time="2026-08-31T15:26:37+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:26:37 bcik go-librespot[2602]: time="2026-08-31T15:26:37+02:00" level=debug msg="app state loaded" Aug 31 15:26:37 bcik go-librespot[2602]: time="2026-08-31T15:26:37+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:26:37 bcik go-librespot[2602]: time="2026-08-31T15:26:37+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]" Aug 31 15:26:37 bcik go-librespot[2602]: time="2026-08-31T15:26:37+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]" Aug 31 15:26:37 bcik go-librespot[2602]: time="2026-08-31T15:26:37+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]" Aug 31 15:26:37 bcik go-librespot[2602]: time="2026-08-31T15:26:37+02:00" level=info msg="zeroconf server listening on port 42457" Aug 31 15:26:37 bcik go-librespot[2602]: time="2026-08-31T15:26:37+02:00" level=debug msg="obtained new client token: AAGVrLWltgdlUeAZ6Q5uKaUI4LCzz+7IoyDiGLjWGgMaV57Xfh7bivWTgx1sVz1As+dYhnyRb2Mx6t2nOtHdWR3aI++bgyI1A3Pp9X7WkFEkXjIkcWwxwQPkshgVPZ+Lrfd/K8yt2lCjckQNQ2C6T3mt1ywRir0VoByhpmkRRIFkFZ9GCAnRyinD/5w12bFdF9uGGsMleDILnCpyCUCuZkjxDTTgiPl/mSXdTzo1QyaC4uI1n+lWY3A=" Aug 31 15:26:37 bcik go-librespot[2602]: time="2026-08-31T15:26:37+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:26:37 bcik go-librespot[2602]: time="2026-08-31T15:26:37+02:00" level=debug msg="completed keyexchange" Aug 31 15:26:37 bcik go-librespot[2602]: time="2026-08-31T15:26:37+02:00" level=debug msg="completed challenge" Aug 31 15:26:37 bcik go-librespot[2602]: time="2026-08-31T15:26:37+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:26:37 bcik go-librespot[2602]: time="2026-08-31T15:26:37+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:26:37 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:26:37 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:26:37 bcik volumio[2154]: info: Initializing connection to go-librespot Websocket Aug 31 15:26:37 bcik volumio[2154]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:26:40 bcik volumio[2154]: info: Initializing connection to go-librespot Websocket Aug 31 15:26:40 bcik volumio[2154]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:26:40 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 279. Aug 31 15:26:40 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:26:40 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:26:40 bcik go-librespot[2625]: go-librespot daemon starting... Aug 31 15:26:40 bcik go-librespot[2626]: time="2026-08-31T15:26:40+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:26:40 bcik go-librespot[2626]: time="2026-08-31T15:26:40+02:00" level=debug msg="app state loaded" Aug 31 15:26:40 bcik go-librespot[2626]: time="2026-08-31T15:26:40+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:26:40 bcik go-librespot[2626]: time="2026-08-31T15:26: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]" Aug 31 15:26:40 bcik go-librespot[2626]: time="2026-08-31T15:26: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]" Aug 31 15:26:40 bcik go-librespot[2626]: time="2026-08-31T15:26: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]" Aug 31 15:26:40 bcik go-librespot[2626]: time="2026-08-31T15:26:40+02:00" level=info msg="zeroconf server listening on port 39739" Aug 31 15:26:40 bcik go-librespot[2626]: time="2026-08-31T15:26:40+02:00" level=debug msg="obtained new client token: AAG4gMZq8FGU9yzp9lIT7JNOMlCLo+tDFn27bWN5p4AC4PZrwBTYbN+bLsa2op+fwQUriz+cRzr2o2sJHp7NslyffJCbTxPmO+h/G+f/khCBhGQ7RNKcqvHQE7q9H+k4VMaXbuGNZGabje2tNXzqcyQ+q03vYLLBcLGgxNbC4k9HnVbINka9fsu4UT7wQMbkjc6q1DU5m9VtblV0v2vfiESNfLa7r2ND3EsmzE1q+ERuRJjXhI+1yZs=" Aug 31 15:26:40 bcik go-librespot[2626]: time="2026-08-31T15:26:40+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:26:41 bcik go-librespot[2626]: time="2026-08-31T15:26:41+02:00" level=debug msg="completed keyexchange" Aug 31 15:26:41 bcik go-librespot[2626]: time="2026-08-31T15:26:41+02:00" level=debug msg="completed challenge" Aug 31 15:26:41 bcik go-librespot[2626]: time="2026-08-31T15:26:41+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:26:41 bcik go-librespot[2626]: time="2026-08-31T15:26:41+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:26:41 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:26:41 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:26:43 bcik volumio[2154]: info: Initializing connection to go-librespot Websocket Aug 31 15:26:43 bcik volumio[2154]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:26:44 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 280. Aug 31 15:26:44 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:26:44 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:26:44 bcik go-librespot[2635]: go-librespot daemon starting... Aug 31 15:26:44 bcik go-librespot[2636]: time="2026-08-31T15:26:44+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:26:44 bcik go-librespot[2636]: time="2026-08-31T15:26:44+02:00" level=debug msg="app state loaded" Aug 31 15:26:44 bcik go-librespot[2636]: time="2026-08-31T15:26:44+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:26:44 bcik go-librespot[2636]: time="2026-08-31T15:26: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 15:26:44 bcik go-librespot[2636]: time="2026-08-31T15:26:44+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]" Aug 31 15:26:44 bcik go-librespot[2636]: time="2026-08-31T15:26:44+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]" Aug 31 15:26:44 bcik go-librespot[2636]: time="2026-08-31T15:26:44+02:00" level=info msg="zeroconf server listening on port 34019" Aug 31 15:26:44 bcik go-librespot[2636]: time="2026-08-31T15:26:44+02:00" level=debug msg="obtained new client token: AAGIk1iSltfcG6eovyHx/WqcyLpjolFwqxvur0fM0PxpNG+7yK8rrk7Up0///LGNyoMPlF363JwR0KfqhohqVJGOP/JciYDY7GTgj6ZDhC84AKA8RqRhyAA7hQWyhHZnHdTY9UKY2f1yyIJnQCIgf3bX4vbNQjz5jN4snZUJLCj1vp6fCjZwutOREYqCZWQt5+0FVEexWKOxRlVZzdsOPZC4gY5jxH0/RacN6qgHNgjuadQS3BoICAI=" Aug 31 15:26:44 bcik go-librespot[2636]: time="2026-08-31T15:26:44+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" Aug 31 15:26:44 bcik go-librespot[2636]: time="2026-08-31T15:26:44+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Aug 31 15:26:44 bcik go-librespot[2636]: time="2026-08-31T15:26:44+02:00" level=debug msg="completed keyexchange" Aug 31 15:26:44 bcik go-librespot[2636]: time="2026-08-31T15:26:44+02:00" level=debug msg="completed challenge" Aug 31 15:26:44 bcik go-librespot[2636]: time="2026-08-31T15:26:44+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:26:44 bcik go-librespot[2636]: time="2026-08-31T15:26:44+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:26:44 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:26:44 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:26:46 bcik volumio[2154]: info: Initializing connection to go-librespot Websocket Aug 31 15:26:46 bcik volumio[2154]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:26:47 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 281. Aug 31 15:26:47 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:26:47 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:26:47 bcik go-librespot[2660]: go-librespot daemon starting... Aug 31 15:26:47 bcik go-librespot[2661]: time="2026-08-31T15:26:47+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:26:47 bcik go-librespot[2661]: time="2026-08-31T15:26:47+02:00" level=debug msg="app state loaded" Aug 31 15:26:47 bcik go-librespot[2661]: time="2026-08-31T15:26:47+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:26:47 bcik go-librespot[2661]: time="2026-08-31T15:26: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-gae2.spotify.com:80]" Aug 31 15:26:47 bcik go-librespot[2661]: time="2026-08-31T15:26:47+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]" Aug 31 15:26:47 bcik go-librespot[2661]: time="2026-08-31T15:26:47+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]" Aug 31 15:26:47 bcik go-librespot[2661]: time="2026-08-31T15:26:47+02:00" level=info msg="zeroconf server listening on port 44381" Aug 31 15:26:47 bcik go-librespot[2661]: time="2026-08-31T15:26:47+02:00" level=debug msg="obtained new client token: AAHtEQGYhWEa/HBnyBBi30u82TxtZefJ5hGMLtVLIihBmF5zZ+s3d58+ljxHrAB+qzMskVAUBWoy0RiIz5RsQbufHo69+YutbPUT4I+aiX2e9xUocOQKo7K1tu8ZJW2KYp3k6tXyAollQaDOBC6B4hs0UcPQfoCCGvVchUWx2cvmsEqn2+oMWcR12/03SW1SQPWd/xv2LU2v05/XaemsXOUF2xB+2We7XX0/5l10hwCd0eaSJ62O5U0=" Aug 31 15:26:47 bcik go-librespot[2661]: time="2026-08-31T15:26:47+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:26:48 bcik go-librespot[2661]: time="2026-08-31T15:26:48+02:00" level=debug msg="completed keyexchange" Aug 31 15:26:48 bcik go-librespot[2661]: time="2026-08-31T15:26:48+02:00" level=debug msg="completed challenge" Aug 31 15:26:48 bcik go-librespot[2661]: time="2026-08-31T15:26:48+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:26:48 bcik go-librespot[2661]: time="2026-08-31T15:26:48+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:26:48 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:26:48 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:26:49 bcik volumio[2154]: info: Initializing connection to go-librespot Websocket Aug 31 15:26:49 bcik volumio[2154]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:26:51 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 282. Aug 31 15:26:51 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:26:51 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:26:51 bcik go-librespot[2670]: go-librespot daemon starting... Aug 31 15:26:51 bcik go-librespot[2671]: time="2026-08-31T15:26:51+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:26:51 bcik go-librespot[2671]: time="2026-08-31T15:26:51+02:00" level=debug msg="app state loaded" Aug 31 15:26:51 bcik go-librespot[2671]: time="2026-08-31T15:26:51+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:26:51 bcik go-librespot[2671]: time="2026-08-31T15:26:51+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]" Aug 31 15:26:51 bcik go-librespot[2671]: time="2026-08-31T15:26:51+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]" Aug 31 15:26:51 bcik go-librespot[2671]: time="2026-08-31T15:26:51+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]" Aug 31 15:26:51 bcik go-librespot[2671]: time="2026-08-31T15:26:51+02:00" level=info msg="zeroconf server listening on port 44755" Aug 31 15:26:51 bcik go-librespot[2671]: time="2026-08-31T15:26:51+02:00" level=debug msg="obtained new client token: AAGQQ+2+wqoOAyJtUfbYZUT82mb+sHeEh1yIjfmkrmsZoGG4OYn+hrFLsqBVsLe+QIqPNXNxi3evVae7YZLgDe599nwpgQ/1JtMIi4EdYVI8JGnovnEstX5U23Xr9BM9HF37d+B3F6ZN8OqFWfCUzsfVLCKy5RSrII0gnDgokFptS23mVqScfKc37L8u5WpsulMEPl3j047+8MT8TDNS1Idze47cr46rYPr4o3HcYTgfCrt46EUCNzM=" Aug 31 15:26:51 bcik go-librespot[2671]: time="2026-08-31T15:26:51+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:26:51 bcik go-librespot[2671]: time="2026-08-31T15:26:51+02:00" level=debug msg="completed keyexchange" Aug 31 15:26:51 bcik go-librespot[2671]: time="2026-08-31T15:26:51+02:00" level=debug msg="completed challenge" Aug 31 15:26:51 bcik go-librespot[2671]: time="2026-08-31T15:26:51+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:26:51 bcik go-librespot[2671]: time="2026-08-31T15:26:51+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:26:51 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:26:51 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:26:52 bcik volumio[2154]: info: Initializing connection to go-librespot Websocket Aug 31 15:26:52 bcik volumio[2154]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:26:54 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 283. Aug 31 15:26:54 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:26:54 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:26:54 bcik go-librespot[2681]: go-librespot daemon starting... Aug 31 15:26:54 bcik go-librespot[2682]: time="2026-08-31T15:26:54+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:26:54 bcik go-librespot[2682]: time="2026-08-31T15:26:54+02:00" level=debug msg="app state loaded" Aug 31 15:26:54 bcik go-librespot[2682]: time="2026-08-31T15:26:54+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:26:54 bcik go-librespot[2682]: time="2026-08-31T15:26: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]" Aug 31 15:26:54 bcik go-librespot[2682]: time="2026-08-31T15:26: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]" Aug 31 15:26:54 bcik go-librespot[2682]: time="2026-08-31T15:26: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]" Aug 31 15:26:54 bcik go-librespot[2682]: time="2026-08-31T15:26:54+02:00" level=info msg="zeroconf server listening on port 43411" Aug 31 15:26:54 bcik go-librespot[2682]: time="2026-08-31T15:26:54+02:00" level=debug msg="obtained new client token: AAHsZMCUy11xBKaVfMDKT4QFFLoDONgeihXpbMaSsfA5SczXvtBoQaf6Pa0CoqtuFNmP4Cdtq7WMyhzmg80w/msOMXtok23ohRf6ORmNQQwrGgrM2Q1km9pCFy9jSoGdQwKDn4V/W0Yiz2RZtnGXUv8DK+2xIwK8+wpiJQgD5cGcMe00/zyy8t0ZY8WCXpfsD6nwEv36l61oLIDd+iINkV/vAh2ISbXg7Z5ZNRyu5K3kuezbzLsPN6I=" Aug 31 15:26:54 bcik go-librespot[2682]: time="2026-08-31T15:26:54+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:26:55 bcik go-librespot[2682]: time="2026-08-31T15:26:55+02:00" level=debug msg="completed keyexchange" Aug 31 15:26:55 bcik go-librespot[2682]: time="2026-08-31T15:26:55+02:00" level=debug msg="completed challenge" Aug 31 15:26:55 bcik go-librespot[2682]: time="2026-08-31T15:26:55+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:26:55 bcik go-librespot[2682]: time="2026-08-31T15:26:55+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:26:55 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:26:55 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:26:55 bcik volumio[2154]: info: Initializing connection to go-librespot Websocket Aug 31 15:26:55 bcik volumio[2154]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:26:58 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 284. Aug 31 15:26:58 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:26:58 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:26:58 bcik go-librespot[2705]: go-librespot daemon starting... Aug 31 15:26:58 bcik go-librespot[2706]: time="2026-08-31T15:26:58+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:26:58 bcik go-librespot[2706]: time="2026-08-31T15:26:58+02:00" level=debug msg="app state loaded" Aug 31 15:26:58 bcik go-librespot[2706]: time="2026-08-31T15:26:58+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:26:58 bcik go-librespot[2706]: time="2026-08-31T15:26: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]" Aug 31 15:26:58 bcik go-librespot[2706]: time="2026-08-31T15:26: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]" Aug 31 15:26:58 bcik go-librespot[2706]: time="2026-08-31T15:26: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]" Aug 31 15:26:58 bcik go-librespot[2706]: time="2026-08-31T15:26:58+02:00" level=info msg="zeroconf server listening on port 42833" Aug 31 15:26:58 bcik go-librespot[2706]: time="2026-08-31T15:26:58+02:00" level=debug msg="obtained new client token: AAH6PPXVB7e1VCYEzHQgYW0O4VxpibcsnJo4COQurxsT3NzIz4oivxMhRW6A4bn8nI7uy6JDRSSrY+cnjpt74bTl6KzGLR6/Hcvsxt7LfqVnxXjziKrRX2nn9omKgNGntiy7vHyC93yxavan8rP/Oa95Nzk0rUWOPd4iFFC2HuPpFw2PX1sto/dy+sogonkN7AE4cAdspg50+3FJhQTBfFF3oZG35P7/5rWH3ruNwDIJNhR3+3j+klc=" Aug 31 15:26:58 bcik go-librespot[2706]: time="2026-08-31T15:26:58+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:26:58 bcik volumio[2154]: info: Initializing connection to go-librespot Websocket Aug 31 15:26:58 bcik go-librespot[2706]: time="2026-08-31T15:26:58+02:00" level=debug msg="new websocket client" Aug 31 15:26:58 bcik volumio[2154]: info: Connection to go-librespot Websocket established Aug 31 15:27:01 bcik go-librespot[2706]: time="2026-08-31T15:27:01+02:00" level=debug msg="completed keyexchange" Aug 31 15:27:01 bcik go-librespot[2706]: time="2026-08-31T15:27:01+02:00" level=debug msg="completed challenge" Aug 31 15:27:01 bcik volumio[2154]: info: Getting Spotify volume Aug 31 15:27:01 bcik go-librespot[2706]: time="2026-08-31T15:27:01+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:27:01 bcik volumio[2154]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Aug 31 15:27:01 bcik volumio[2154]: info: CoreCommandRouter::volumioGetState Aug 31 15:27:01 bcik volumio[2154]: info: CorePlayQueue::getTrack 0 Aug 31 15:27:01 bcik volumio[2154]: SPOTIFY: RECEIVED VOLUMIO VOLUME 53 Aug 31 15:27:01 bcik volumio[2154]: SPOTIFY: SPOTIFY VOLUME undefined Aug 31 15:27:01 bcik volumio[2154]: SPOTIFY: VOLUMIO VOLUME 53 Aug 31 15:27:01 bcik volumio[2154]: info: Aligning Spotify Volume to Volumio Volume Aug 31 15:27:01 bcik volumio[2154]: info: CoreCommandRouter::volumioGetState Aug 31 15:27:01 bcik volumio[2154]: info: CorePlayQueue::getTrack 0 Aug 31 15:27:01 bcik volumio[2154]: info: Setting Spotify Volume from Volumio: 53 Aug 31 15:27:01 bcik go-librespot[2706]: time="2026-08-31T15:27:01+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:27:01 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:27:01 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:27:01 bcik volumio[2154]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 15:27:01 bcik volumio[2154]: Error: socket hang up Aug 31 15:27:01 bcik volumio[2154]: at connResetException (node:internal/errors:720:14) Aug 31 15:27:01 bcik volumio[2154]: at Socket.socketOnEnd (node:_http_client:519:23) Aug 31 15:27:01 bcik volumio[2154]: at Socket.emit (node:events:526:35) Aug 31 15:27:01 bcik volumio[2154]: at endReadableNT (node:internal/streams/readable:1376:12) Aug 31 15:27:01 bcik volumio[2154]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Aug 31 15:27:01 bcik volumio[2154]: code: 'ECONNRESET', Aug 31 15:27:01 bcik volumio[2154]: response: undefined Aug 31 15:27:01 bcik volumio[2154]: } Aug 31 15:27:01 bcik volumio[2154]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 15:27:01 bcik sudo[2729]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-31 15:26' Aug 31 15:27:01 bcik sudo[2729]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:27:01 bcik sudo[2729]: pam_unix(sudo:session): session closed for user root Aug 31 15:27:02 bcik volumio-remote-updater[962]: [2026-08-31 15:27:02] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Aug 31 15:27:02 bcik volumio-remote-updater[962]: [2026-08-31 15:27:02] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Aug 31 15:27:02 bcik volumio5-onboarding[1666]: time=2026-08-31T15:27:02.169+02:00 level=ERROR msg="failed reading message" error="websocket: close 1006 (abnormal closure): unexpected EOF" Aug 31 15:27:02 bcik volumio5-onboarding[1666]: time=2026-08-31T15:27:02.170+02:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Aug 31 15:27:02 bcik systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:27:02 bcik systemd[1]: volumio.service: Failed with result 'exit-code'. Aug 31 15:27:02 bcik systemd[1]: volumio.service: Consumed 6.884s CPU time. Aug 31 15:27:02 bcik systemd[1]: Started dynamicswap.service - dynamicswap service. Aug 31 15:27:02 bcik systemd[1]: dynamicswap.service: Deactivated successfully. Aug 31 15:27:02 bcik systemd[1]: volumio.service: Scheduled restart job, restart counter is at 187. Aug 31 15:27:02 bcik systemd[1]: Started dynamicswap.service - dynamicswap service. Aug 31 15:27:02 bcik systemd[1]: Stopped volumio.service - Volumio Backend Module. Aug 31 15:27:02 bcik systemd[1]: volumio.service: Consumed 6.884s CPU time. Aug 31 15:27:02 bcik systemd[1]: Started volumio.service - Volumio Backend Module. Aug 31 15:27:02 bcik systemd[1]: dynamicswap.service: Deactivated successfully. Aug 31 15:27:02 bcik volumio[2747]: info: ------------------------------------------- Aug 31 15:27:02 bcik volumio[2747]: info: ----- Volumio3 ---- Aug 31 15:27:02 bcik volumio[2747]: info: ------------------------------------------- Aug 31 15:27:02 bcik volumio[2747]: info: ----- System startup ---- Aug 31 15:27:02 bcik volumio[2747]: info: ------------------------------------------- Aug 31 15:27:03 bcik volumio[2747]: info: MYVOLUMIO Environment detected Aug 31 15:27:03 bcik volumio[2747]: info: Plugin folders cleanup Aug 31 15:27:03 bcik volumio[2747]: info: Scanning into folder /volumio/app/plugins/ Aug 31 15:27:03 bcik volumio[2747]: info: Scanning category audio_interface Aug 31 15:27:03 bcik volumio[2747]: info: Scanning category miscellanea Aug 31 15:27:03 bcik volumio[2747]: info: Scanning category music_service Aug 31 15:27:03 bcik volumio[2747]: info: Scanning category plugins.json Aug 31 15:27:03 bcik volumio[2747]: info: Scanning category system_controller Aug 31 15:27:03 bcik volumio[2747]: info: Scanning category user_interface Aug 31 15:27:03 bcik volumio[2747]: info: Scanning into folder /data/plugins/ Aug 31 15:27:03 bcik volumio[2747]: info: Scanning category music_service Aug 31 15:27:03 bcik volumio[2747]: info: Plugin folders cleanup completed Aug 31 15:27:03 bcik volumio[2747]: info: ------------------------------------------- Aug 31 15:27:03 bcik volumio[2747]: info: ----- Core plugins startup ---- Aug 31 15:27:03 bcik volumio[2747]: info: ------------------------------------------- Aug 31 15:27:03 bcik volumio[2747]: info: Loading plugins from folder /volumio/app/plugins/ Aug 31 15:27:03 bcik volumio[2747]: info: Adding plugin upnp to MyMusic Plugins Aug 31 15:27:03 bcik volumio[2747]: info: Adding plugin airplay_emulation to MyMusic Plugins Aug 31 15:27:03 bcik volumio[2747]: info: Adding plugin upnp_browser to MyMusic Plugins Aug 31 15:27:03 bcik volumio[2747]: info: Loading plugins from folder /data/plugins/ Aug 31 15:27:03 bcik volumio[2747]: info: Loading plugin "system"... Aug 31 15:27:03 bcik volumio[2747]: info: Loading plugin "appearance"... Aug 31 15:27:03 bcik volumio[2747]: info: Loading plugin "network"... Aug 31 15:27:03 bcik volumio[2747]: info: Refreshing Cached IP Addresses Aug 31 15:27:03 bcik sudo[2775]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 31 15:27:03 bcik sudo[2775]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:27:03 bcik sudo[2777]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 31 15:27:03 bcik sudo[2777]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:27:03 bcik volumio[2747]: info: Loading plugin "services"... Aug 31 15:27:03 bcik sudo[2777]: pam_unix(sudo:session): session closed for user root Aug 31 15:27:03 bcik volumio[2747]: info: Loading plugin "volumio5onboarding"... Aug 31 15:27:03 bcik sudo[2775]: pam_unix(sudo:session): session closed for user root Aug 31 15:27:03 bcik volumio[2747]: info: Loading plugin "alsa_controller"... Aug 31 15:27:03 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 15:27:03 bcik volumio[2747]: info: Loading plugin "wizard"... Aug 31 15:27:03 bcik volumio[2747]: info: Loading plugin "networkfs"... Aug 31 15:27:03 bcik volumio[2747]: info: Starting Udev Watcher for removable devices Aug 31 15:27:03 bcik volumio[2747]: info: Ignoring mount for partition: boot Aug 31 15:27:03 bcik volumio[2747]: info: Ignoring mount for partition: volumio Aug 31 15:27:03 bcik volumio[2747]: info: Ignoring mount for partition: volumio_data Aug 31 15:27:03 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 15:27:03 bcik volumio[2747]: info: Loading plugin "volumio_command_line_client"... Aug 31 15:27:03 bcik volumio[2747]: info: Loading plugin "upnp"... Aug 31 15:27:03 bcik volumio[2747]: info: [1788182823330] Starting Upmpd Daemon Aug 31 15:27:03 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 15:27:03 bcik volumio[2747]: info: Loading plugin "my_music"... Aug 31 15:27:03 bcik volumio[2747]: info: Loading plugin "mpd"... Aug 31 15:27:03 bcik volumio[2747]: info: Loading plugin "upnp_browser"... Aug 31 15:27:03 bcik volumio[2747]: info: Starting UPNP Browser Aug 31 15:27:03 bcik volumio[2747]: info: Loading plugin "alarm-clock"... Aug 31 15:27:03 bcik volumio[2747]: info: Loading plugin "airplay_emulation"... Aug 31 15:27:03 bcik volumio[2747]: info: Starting Shairport Sync Aug 31 15:27:03 bcik volumio[2747]: info: Loading plugin "last_100"... Aug 31 15:27:03 bcik volumio[2747]: info: Loading plugin "webradio"... Aug 31 15:27:03 bcik volumio[2747]: info: Loading plugin "i2s_dacs"... Aug 31 15:27:03 bcik volumio[2747]: info: Loading plugin "volumiodiscovery"... Aug 31 15:27:03 bcik volumio[2747]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 31 15:27:03 bcik volumio[2747]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 15:27:03 bcik volumio[2747]: *** WARNING *** For more information see Aug 31 15:27:03 bcik volumio[2747]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 31 15:27:03 bcik volumio[2747]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 15:27:03 bcik volumio[2747]: *** WARNING *** For more information see Aug 31 15:27:03 bcik node[2747]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 31 15:27:03 bcik node[2747]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 15:27:03 bcik node[2747]: *** WARNING *** For more information see Aug 31 15:27:03 bcik node[2747]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 31 15:27:03 bcik node[2747]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 15:27:03 bcik node[2747]: *** WARNING *** For more information see Aug 31 15:27:03 bcik volumio[2747]: info: Applying required configuration parameters for plugin volumiodiscovery Aug 31 15:27:03 bcik volumio[2747]: info: Discovery: Started advertising with name: Bącik Aug 31 15:27:03 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 15:27:03 bcik volumio[2747]: info: Loading plugin "spop"... Aug 31 15:27:03 bcik volumio[2747]: info: Loading plugin "outputs"... Aug 31 15:27:03 bcik volumio[2747]: info: Loading plugin "albumart"... Aug 31 15:27:03 bcik volumio[2747]: info: Plugin example_plugin is not enabled Aug 31 15:27:03 bcik volumio[2747]: info: Loading plugin "inputs"... Aug 31 15:27:03 bcik volumio[2747]: info: Loading plugin "updater_comm"... Aug 31 15:27:03 bcik volumio[2747]: info: Plugin mpdemulation is not enabled Aug 31 15:27:03 bcik volumio[2747]: info: Loading plugin "rest_api"... Aug 31 15:27:03 bcik volumio[2747]: info: Loading plugin "websocket"... Aug 31 15:27:03 bcik volumio[2747]: info: Starting Socket.io Server version 1.7.4 Aug 31 15:27:03 bcik volumio[2747]: info: Loading plugin "radio_browser"... Aug 31 15:27:04 bcik volumio[2807]: Forking 3 albumart workers Aug 31 15:27:04 bcik volumio[2747]: info: Loading i18n strings for locale pl Aug 31 15:27:04 bcik volumio[2747]: Updating browse sources language Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::initPlayerControls Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 15:27:04 bcik volumio[2747]: Express server listening on port 3000 Aug 31 15:27:04 bcik volumio[2747]: [Metrics] WebUI: 1s 287.38ms Aug 31 15:27:04 bcik volumio[2747]: info: CoreStateMachine::resetVolumioState Aug 31 15:27:04 bcik volumio[2747]: info: CoreStateMachine::getcurrentVolume Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::volumioRetrievevolume Aug 31 15:27:04 bcik volumio[2747]: info: Volumio Network Manager: Network status updated: 1 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: info: VolumeController:: Volume=53 Mute =false Aug 31 15:27:04 bcik volumio[2747]: info: CoreStateMachine::pushState Aug 31 15:27:04 bcik volumio[2747]: info: CorePlayQueue::getTrack 0 Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::volumioPushState Aug 31 15:27:04 bcik volumio[2747]: info: CoreStateMachine::updateTrackBlock Aug 31 15:27:04 bcik volumio[2747]: info: CorePlayQueue::getTrackBlock Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::volumioRetrievevolume Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:27:04 bcik volumio[2747]: info: Reloading queue from file Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: info: CoreStateMachine::setRepeat false single undefined Aug 31 15:27:04 bcik volumio[2747]: info: CoreStateMachine::pushState Aug 31 15:27:04 bcik volumio[2747]: info: CorePlayQueue::getTrack 0 Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::volumioPushState Aug 31 15:27:04 bcik volumio[2747]: info: CoreStateMachine::setRandom false Aug 31 15:27:04 bcik volumio[2747]: info: CoreStateMachine::pushState Aug 31 15:27:04 bcik volumio[2747]: info: CorePlayQueue::getTrack 0 Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::volumioPushState Aug 31 15:27:04 bcik volumio[2747]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Aug 31 15:27:04 bcik volumio[2747]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04171 Aug 31 15:27:04 bcik volumio[2747]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: info: Setting Device type: Raspberry PI Aug 31 15:27:04 bcik volumio[2747]: info: Completed loading Core Plugins Aug 31 15:27:04 bcik volumio[2747]: info: Preparing to generate the ALSA configuration file Aug 31 15:27:04 bcik volumio[2747]: info: VolumeController:: Volume=53 Mute =false Aug 31 15:27:04 bcik volumio[2747]: info: CoreStateMachine::pushState Aug 31 15:27:04 bcik volumio[2747]: info: CorePlayQueue::getTrack 0 Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::volumioPushState Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: info: Asound.conf file unchanged, so no further update is needed Aug 31 15:27:04 bcik volumio[2747]: info: Output device has changed, restarting MPD Aug 31 15:27:04 bcik volumio[2747]: info: Output device has changed, restarting Shairport Sync Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:27:04 bcik sudo[2863]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 31 15:27:04 bcik sudo[2863]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:27:04 bcik sudo[2863]: pam_unix(sudo:session): session closed for user root Aug 31 15:27:04 bcik sudo[2865]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 31 15:27:04 bcik sudo[2865]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:27:04 bcik volumio[2747]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 31 15:27:04 bcik volumio[2747]: info: ___________ START PLUGINS ___________ Aug 31 15:27:04 bcik volumio[2747]: info: ControllerMpd::onStart: Initializing MPD Aug 31 15:27:04 bcik volumio[2747]: info: Creating MPD Configuration file Aug 31 15:27:04 bcik systemd[1]: Stopping mpd.service - Music Player Daemon... Aug 31 15:27:04 bcik sudo[2873]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Aug 31 15:27:04 bcik sudo[2873]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:27:04 bcik systemd[1]: mpd.service: Deactivated successfully. Aug 31 15:27:04 bcik sudo[2875]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 31 15:27:04 bcik sudo[2875]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:27:04 bcik sudo[2875]: pam_unix(sudo:session): session closed for user root Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 15:27:04 bcik volumio[2747]: info: [1788182824341] CoreMusicLibrary::Adding element Serwery Mediów Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 15:27:04 bcik systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 31 15:27:04 bcik systemd[1]: mpd.socket: Deactivated successfully. Aug 31 15:27:04 bcik systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 31 15:27:04 bcik systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 31 15:27:04 bcik volumio[2747]: info: UPNP Browser: Client initialized successfully Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:27:04 bcik sudo[2877]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 31 15:27:04 bcik sudo[2877]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:27:04 bcik volumio[2747]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 31 15:27:04 bcik volumio[2819]: Starting albumart workers Aug 31 15:27:04 bcik volumio[2817]: Starting albumart workers Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:27:04 bcik systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 31 15:27:04 bcik systemd[1]: Starting mpd.service - Music Player Daemon... Aug 31 15:27:04 bcik volumio[2747]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 15:27:04 bcik volumio[2747]: info: [1788182824381] CoreMusicLibrary::Adding element Last_100 Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 15:27:04 bcik volumio[2747]: info: [1788182824382] CoreMusicLibrary::Adding element Webradio Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 15:27:04 bcik volumio[2747]: info: Initializing BBC Radios Aug 31 15:27:04 bcik volumio[2818]: Starting albumart workers Aug 31 15:27:04 bcik systemd[1]: mpd.service: Deactivated successfully. Aug 31 15:27:04 bcik systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 31 15:27:04 bcik systemd[1]: mpd.socket: Deactivated successfully. Aug 31 15:27:04 bcik systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 31 15:27:04 bcik systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 31 15:27:04 bcik sudo[2873]: pam_unix(sudo:session): session closed for user root Aug 31 15:27:04 bcik systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 31 15:27:04 bcik systemd[1]: Starting mpd.service - Music Player Daemon... Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:27:04 bcik volumio[2747]: info: Creating Spotify config file Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:27:04 bcik sudo[2900]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 31 15:27:04 bcik sudo[2900]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 31 15:27:04 bcik sudo[2900]: pam_unix(sudo:session): session closed for user root Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 15:27:04 bcik volumio[2747]: info: [1788182824601] CoreMusicLibrary::Adding element Radio Browser Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 15:27:04 bcik volumio[2747]: Cannot find translation for source Radio Browser Aug 31 15:27:04 bcik volumio[2747]: info: Volumio Calling Home Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: info: MPD Permissions set Aug 31 15:27:04 bcik volumio[2747]: info: MPD Permissions set Aug 31 15:27:04 bcik volumio[2747]: info: Spotify config file written Aug 31 15:27:04 bcik volumio[2747]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Aug 31 15:27:04 bcik sudo[2931]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 31 15:27:04 bcik sudo[2931]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:27:04 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:27:04 bcik volumio[2747]: info: No need to fix Spotify hosts Aug 31 15:27:04 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik sudo[2931]: pam_unix(sudo:session): session closed for user root Aug 31 15:27:04 bcik go-librespot[2938]: go-librespot daemon starting... Aug 31 15:27:04 bcik go-librespot[2944]: time="2026-08-31T15:27:04+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:27:04 bcik go-librespot[2944]: time="2026-08-31T15:27:04+02:00" level=debug msg="app state loaded" Aug 31 15:27:04 bcik go-librespot[2944]: time="2026-08-31T15:27:04+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:27:04 bcik volumio[2747]: info: Volumio called home Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: info: Starting Shairport Sync Aug 31 15:27:04 bcik volumio[2747]: info: Starting Shairport Sync Aug 31 15:27:04 bcik volumio[2747]: info: Starting Shairport Sync Aug 31 15:27:04 bcik sudo[2952]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 31 15:27:04 bcik sudo[2952]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:27:04 bcik sudo[2955]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 31 15:27:04 bcik sudo[2958]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 31 15:27:04 bcik sudo[2958]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:27:04 bcik sudo[2955]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:27:04 bcik volumio[2747]: info: Discovery: adding f1ed5fb6-e21d-47c8-819b-29842600355e Aug 31 15:27:04 bcik volumio[2747]: info: Discovery: Found device Bącik Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::volumioGetState Aug 31 15:27:04 bcik volumio[2747]: info: CorePlayQueue::getTrack 0 Aug 31 15:27:04 bcik systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 31 15:27:04 bcik systemd[1]: shairport-sync.service: Deactivated successfully. Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 31 15:27:04 bcik systemd[1]: shairport-sync.service: Consumed 1.518s CPU time. Aug 31 15:27:04 bcik go-librespot[2944]: time="2026-08-31T15:27:04+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]" Aug 31 15:27:04 bcik go-librespot[2944]: time="2026-08-31T15:27:04+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]" Aug 31 15:27:04 bcik go-librespot[2944]: time="2026-08-31T15:27:04+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]" Aug 31 15:27:04 bcik volumio[2747]: info: Discovery: this is already registered, f1ed5fb6-e21d-47c8-819b-29842600355e Aug 31 15:27:04 bcik volumio[2747]: info: Discovery: Found device Bącik Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::volumioGetState Aug 31 15:27:04 bcik volumio[2747]: info: CorePlayQueue::getTrack 0 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik go-librespot[2944]: time="2026-08-31T15:27:04+02:00" level=info msg="zeroconf server listening on port 34783" Aug 31 15:27:04 bcik volumio[2747]: info: An error occurred while refreshing Spotify Token Error: Bad Request Aug 31 15:27:04 bcik volumio[2747]: info: CoreCommandRouter::volumioGetState Aug 31 15:27:04 bcik volumio[2747]: info: CorePlayQueue::getTrack 0 Aug 31 15:27:04 bcik systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 31 15:27:04 bcik sudo[2955]: pam_unix(sudo:session): session closed for user root Aug 31 15:27:04 bcik sudo[2958]: pam_unix(sudo:session): session closed for user root Aug 31 15:27:04 bcik sudo[2952]: pam_unix(sudo:session): session closed for user root Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: info: Shairport-Sync Started Aug 31 15:27:04 bcik volumio[2747]: Error adding Membership: Error: addMembership EINVAL Aug 31 15:27:04 bcik volumio[2747]: info: Shairport-Sync Started Aug 31 15:27:04 bcik volumio[2747]: info: Shairport-Sync Started Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik go-librespot[2944]: time="2026-08-31T15:27:04+02:00" level=debug msg="obtained new client token: AAHjJgBfwlUM1UpV0Jtp8X7Cerf+jI2guFryqUm/9btEATwfVbXGHFBnLT1NvPt7FgX1904xi/E+9vGyBtkiNymvJxu3TdloVjimRXAIrDLW6LASYST6rCPYuCwrIRbBneqBfvwPOELh+/xvI7XB4q7P7vlvWyadKRgLzG+NtSHclDriLkgdW2paDfJX8ucvv8YyDpaL7bdE0aAeHLAWsLOfgDpZQHSP2SNvGRk7CLckTVS8agkYHZU=" Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik go-librespot[2944]: time="2026-08-31T15:27:04+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik go-librespot[2944]: time="2026-08-31T15:27:04+02:00" level=debug msg="completed keyexchange" Aug 31 15:27:04 bcik go-librespot[2944]: time="2026-08-31T15:27:04+02:00" level=debug msg="completed challenge" Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik go-librespot[2944]: time="2026-08-31T15:27:04+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:04 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik mpd[2907]: 2026-08-31T15:27:05 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 31 15:27:05 bcik systemd[1]: Started mpd.service - Music Player Daemon. Aug 31 15:27:05 bcik sudo[2877]: pam_unix(sudo:session): session closed for user root Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik sudo[2865]: pam_unix(sudo:session): session closed for user root Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: info: Completed starting Core Plugins Aug 31 15:27:05 bcik volumio[2747]: info: ------------------------------------------- Aug 31 15:27:05 bcik volumio[2747]: info: ----- MyVolumio plugins startup ---- Aug 31 15:27:05 bcik volumio[2747]: info: ------------------------------------------- Aug 31 15:27:05 bcik volumio[2747]: info: [MyVolumio PluginManager] Fetching plans data.... Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: error: MPD error: The expression evaluated to a falsy value: Aug 31 15:27:05 bcik volumio[2747]: assert.ok(self.idling) Aug 31 15:27:05 bcik volumio[2747]: error: The expression evaluated to a falsy value: Aug 31 15:27:05 bcik volumio[2747]: assert.ok(self.idling) Aug 31 15:27:05 bcik go-librespot[2944]: time="2026-08-31T15:27:05+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:27:05 bcik volumio[2747]: error: updateQueue error: null Aug 31 15:27:05 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:27:05 bcik volumio[2747]: info: MPD running with PID2907 Aug 31 15:27:05 bcik volumio[2747]: ,establishing connection Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: error: updateQueue error: null Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:05 bcik volumio[2747]: 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 Aug 31 15:27:07 bcik volumio-remote-updater[962]: [2026-08-31 15:27:07] [connect] Successful connection Aug 31 15:27:07 bcik volumio-remote-updater[962]: [2026-08-31 15:27:07] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1788182827 101 Aug 31 15:27:07 bcik volumio[2747]: 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 Aug 31 15:27:07 bcik volumio[2747]: info: go-librespot daemon successfully initialized Aug 31 15:27:08 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 285. Aug 31 15:27:08 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:27:08 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:27:08 bcik go-librespot[2985]: go-librespot daemon starting... Aug 31 15:27:08 bcik go-librespot[2986]: time="2026-08-31T15:27:08+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:27:08 bcik go-librespot[2986]: time="2026-08-31T15:27:08+02:00" level=debug msg="app state loaded" Aug 31 15:27:08 bcik go-librespot[2986]: time="2026-08-31T15:27:08+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:27:08 bcik go-librespot[2986]: time="2026-08-31T15:27: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-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 15:27:08 bcik go-librespot[2986]: time="2026-08-31T15:27:08+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]" Aug 31 15:27:08 bcik go-librespot[2986]: time="2026-08-31T15:27:08+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]" Aug 31 15:27:08 bcik go-librespot[2986]: time="2026-08-31T15:27:08+02:00" level=info msg="zeroconf server listening on port 33731" Aug 31 15:27:08 bcik go-librespot[2986]: time="2026-08-31T15:27:08+02:00" level=debug msg="obtained new client token: AAFYCiL6Z64+hCBBz32vZRzTlrhofnZO5cUMKqQuMDBhyqDlte/EBK/uG1MuzHzkHCGz5YERQsrYfNt1mziZRyDOEJu+Z+VK0w8lH9piHrdcx87JAGPIik+SW/vYMNQcBUy3pWElt5Mjuhb9sZqCjLV/DOhQVeZhuvJOBnrjlQv7nR8ggll3VFrTI10Vu0CAkZw3W/bVRUdfG+D/vxO7LHlKkuomV9qucsTmKROpomMhlgvZ4tLXU6M=" Aug 31 15:27:08 bcik go-librespot[2986]: time="2026-08-31T15:27:08+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:27:08 bcik go-librespot[2986]: time="2026-08-31T15:27:08+02:00" level=debug msg="completed keyexchange" Aug 31 15:27:08 bcik go-librespot[2986]: time="2026-08-31T15:27:08+02:00" level=debug msg="completed challenge" Aug 31 15:27:08 bcik go-librespot[2986]: time="2026-08-31T15:27:08+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:27:08 bcik go-librespot[2986]: time="2026-08-31T15:27:08+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:27:08 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:27:08 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:27:10 bcik volumio[2747]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Aug 31 15:27:10 bcik volumio[2747]: info: Initializing connection to go-librespot Websocket Aug 31 15:27:10 bcik volumio[2747]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:27:11 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 286. Aug 31 15:27:11 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:27:11 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:27:11 bcik go-librespot[2995]: go-librespot daemon starting... Aug 31 15:27:11 bcik go-librespot[2996]: time="2026-08-31T15:27:11+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:27:11 bcik go-librespot[2996]: time="2026-08-31T15:27:11+02:00" level=debug msg="app state loaded" Aug 31 15:27:11 bcik go-librespot[2996]: time="2026-08-31T15:27:11+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:27:11 bcik go-librespot[2996]: time="2026-08-31T15:27:11+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]" Aug 31 15:27:11 bcik go-librespot[2996]: time="2026-08-31T15:27:11+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]" Aug 31 15:27:11 bcik go-librespot[2996]: time="2026-08-31T15:27:11+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]" Aug 31 15:27:11 bcik go-librespot[2996]: time="2026-08-31T15:27:11+02:00" level=info msg="zeroconf server listening on port 35371" Aug 31 15:27:11 bcik go-librespot[2996]: time="2026-08-31T15:27:11+02:00" level=debug msg="obtained new client token: AAHD5rjOo5aRBytjVj6YJz56X28Vn020lXgzqotgqi4uxPfR5DXDlFLGWbBe0KPw8e+4MipmmrYYzEZFpLfBU1+jLB0tHN02RBa4zPUEZEZ6I6BuXsXyy8OLbamHyZ58hbEhSrSUjWyzjgmuexp7DC7cUUce02tZidk2SpssdSqVpDjT6cIUBz6+Ve2QD5W6CFBvsbrTgvClSKCgSyZn0ZWPMr+ciCqlWTOZVWh3JO12yTqZJQ0coCY=" Aug 31 15:27:11 bcik go-librespot[2996]: time="2026-08-31T15:27:11+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" Aug 31 15:27:12 bcik go-librespot[2996]: time="2026-08-31T15:27:12+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Aug 31 15:27:12 bcik go-librespot[2996]: time="2026-08-31T15:27:12+02:00" level=debug msg="completed keyexchange" Aug 31 15:27:12 bcik go-librespot[2996]: time="2026-08-31T15:27:12+02:00" level=debug msg="completed challenge" Aug 31 15:27:12 bcik go-librespot[2996]: time="2026-08-31T15:27:12+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:27:12 bcik go-librespot[2996]: time="2026-08-31T15:27:12+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:27:12 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:27:12 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:27:13 bcik sudo[3020]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 31 15:27:13 bcik sudo[3020]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:27:13 bcik sudo[3022]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 31 15:27:13 bcik sudo[3022]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:27:13 bcik sudo[3022]: pam_unix(sudo:session): session closed for user root Aug 31 15:27:13 bcik sudo[3020]: pam_unix(sudo:session): session closed for user root Aug 31 15:27:13 bcik sudo[3026]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Aug 31 15:27:13 bcik sudo[3026]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:27:13 bcik volumio[2747]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Aug 31 15:27:13 bcik volumio[2747]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Aug 31 15:27:13 bcik volumio[2747]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Aug 31 15:27:13 bcik volumio[2747]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Aug 31 15:27:13 bcik volumio[2747]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Aug 31 15:27:13 bcik volumio[2747]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Aug 31 15:27:13 bcik volumio[2747]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Aug 31 15:27:13 bcik volumio[2747]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Aug 31 15:27:13 bcik volumio[2747]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Aug 31 15:27:13 bcik volumio[2747]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Aug 31 15:27:13 bcik volumio[2747]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Aug 31 15:27:13 bcik volumio[2747]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Aug 31 15:27:13 bcik volumio[2747]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Aug 31 15:27:13 bcik volumio[2747]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Aug 31 15:27:13 bcik volumio[2747]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Aug 31 15:27:13 bcik volumio[2747]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Aug 31 15:27:13 bcik volumio[2747]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Aug 31 15:27:13 bcik volumio[2747]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Aug 31 15:27:13 bcik volumio[2747]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Aug 31 15:27:13 bcik volumio[2747]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Aug 31 15:27:13 bcik volumio[2747]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Aug 31 15:27:13 bcik volumio[2747]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Aug 31 15:27:13 bcik volumio[2747]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Aug 31 15:27:13 bcik volumio[2747]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Aug 31 15:27:13 bcik volumio[2747]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Aug 31 15:27:13 bcik volumio[2747]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Aug 31 15:27:13 bcik volumio[2747]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Aug 31 15:27:13 bcik volumio[2747]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Aug 31 15:27:13 bcik volumio[2747]: info: Adding plugin bluetooth to MyMusic Plugins Aug 31 15:27:13 bcik volumio[2747]: info: Adding plugin multiroom to MyMusic Plugins Aug 31 15:27:13 bcik volumio[2747]: info: Adding plugin metavolumio to MyMusic Plugins Aug 31 15:27:13 bcik volumio[2747]: info: Adding plugin cd_controller to MyMusic Plugins Aug 31 15:27:13 bcik volumio[2747]: info: Adding plugin qobuzconnect to MyMusic Plugins Aug 31 15:27:13 bcik volumio[2747]: info: Adding plugin smart_inputs to MyMusic Plugins Aug 31 15:27:13 bcik volumio[2747]: info: Adding plugin tidalconnect to MyMusic Plugins Aug 31 15:27:13 bcik volumio[2747]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Aug 31 15:27:13 bcik sudo[3026]: pam_unix(sudo:session): session closed for user root Aug 31 15:27:13 bcik volumio[2747]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Aug 31 15:27:13 bcik volumio[2747]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Aug 31 15:27:13 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:27:13 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:27:13 bcik volumio[2747]: info: Starting MyVolumio Remote Streaming Endpoints Aug 31 15:27:13 bcik volumio[2747]: info: MyVolumio login type: Token Aug 31 15:27:13 bcik volumio[2747]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Aug 31 15:27:13 bcik volumio[2747]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Aug 31 15:27:13 bcik volumio[2747]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Aug 31 15:27:13 bcik volumio[2747]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Aug 31 15:27:13 bcik volumio[2747]: info: Streaming services startup Aug 31 15:27:13 bcik volumio[2747]: info: Starting Streaming Daemon Aug 31 15:27:13 bcik volumio[2747]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Aug 31 15:27:13 bcik sudo[3029]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 31 15:27:13 bcik sudo[3029]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:27:13 bcik volumio[2747]: info: Initializing connection to go-librespot Websocket Aug 31 15:27:13 bcik sudo[3029]: pam_unix(sudo:session): session closed for user root Aug 31 15:27:13 bcik volumio[2747]: info: Upmpdcli Daemon Started Aug 31 15:27:13 bcik volumio[2747]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:27:13 bcik volumio[2747]: error: Cannot start Volumio Streaming Daemon Aug 31 15:27:13 bcik volumio[2747]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 31 15:27:13 bcik volumio[2747]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 31 15:27:14 bcik volumio[2747]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Aug 31 15:27:14 bcik volumio[2747]: info: MyVolumio token set successfully Aug 31 15:27:14 bcik volumio[2747]: info: MYVOLUMIO: Adding device Aug 31 15:27:14 bcik volumio[2747]: info: MYVOLUMIO: Evaluating Server Aug 31 15:27:14 bcik volumio[2747]: info: MyVolumio status changed Aug 31 15:27:14 bcik volumio[2747]: info: Streaming services startup Aug 31 15:27:14 bcik volumio[2747]: info: Starting Streaming Daemon Aug 31 15:27:14 bcik volumio[2747]: info: Removing browser output: myVolumio user plan is not superstar Aug 31 15:27:14 bcik volumio[2747]: info: Removing audio output: Aug 31 15:27:14 bcik volumio[2747]: info: Stoppping Tunnel 1 Aug 31 15:27:14 bcik sudo[3057]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 31 15:27:14 bcik sudo[3057]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:27:14 bcik sudo[3059]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Aug 31 15:27:14 bcik sudo[3059]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 15:27:14 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. Aug 31 15:27:14 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. Aug 31 15:27:14 bcik sudo[3057]: pam_unix(sudo:session): session closed for user root Aug 31 15:27:14 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. Aug 31 15:27:14 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. Aug 31 15:27:14 bcik volumio[2747]: error: Cannot start Volumio Streaming Daemon Aug 31 15:27:14 bcik volumio[2747]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 31 15:27:14 bcik volumio[2747]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 31 15:27:14 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. Aug 31 15:27:14 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. Aug 31 15:27:14 bcik sudo[3059]: pam_unix(sudo:session): session closed for user root Aug 31 15:27:14 bcik volumio[2747]: info: Remote SSH Stopped Aug 31 15:27:15 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 287. Aug 31 15:27:15 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:27:15 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:27:15 bcik go-librespot[3062]: go-librespot daemon starting... Aug 31 15:27:15 bcik go-librespot[3063]: time="2026-08-31T15:27:15+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:27:15 bcik go-librespot[3063]: time="2026-08-31T15:27:15+02:00" level=debug msg="app state loaded" Aug 31 15:27:15 bcik go-librespot[3063]: time="2026-08-31T15:27:15+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:27:15 bcik go-librespot[3063]: time="2026-08-31T15:27: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-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 15:27:15 bcik go-librespot[3063]: time="2026-08-31T15:27:15+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]" Aug 31 15:27:15 bcik go-librespot[3063]: time="2026-08-31T15:27:15+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]" Aug 31 15:27:15 bcik go-librespot[3063]: time="2026-08-31T15:27:15+02:00" level=info msg="zeroconf server listening on port 33775" Aug 31 15:27:15 bcik go-librespot[3063]: time="2026-08-31T15:27:15+02:00" level=debug msg="obtained new client token: AAHmv1OErkhl1NzCfW8ERZiZS55sT+ZV6f660w/I3MVeUJrmxSuMNTOSi5Xcjpui5WtkPuoER3AKTgHsNSWSD44Mx4zosfpIiVQIGPIOpKPVKE7Eq1sx9+S5rhdlMtj+H1K6rbTCpXZJcG3uKlVxa3fDsX58408893OrE9P55F2yI6Ql8OwcBsiKSHv+ZFVDPYUAwDoiAi954t+UrzMiobGPHm7rOU7TFOYGsomfHbQpeLh91lyISzI=" Aug 31 15:27:15 bcik go-librespot[3063]: time="2026-08-31T15:27:15+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:27:15 bcik go-librespot[3063]: time="2026-08-31T15:27:15+02:00" level=debug msg="completed keyexchange" Aug 31 15:27:15 bcik go-librespot[3063]: time="2026-08-31T15:27:15+02:00" level=debug msg="completed challenge" Aug 31 15:27:15 bcik go-librespot[3063]: time="2026-08-31T15:27:15+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:27:16 bcik go-librespot[3063]: time="2026-08-31T15:27:16+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:27:16 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:27:16 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:27:16 bcik volumio[2747]: info: Setting Geolocation for MyVolumio to eu6 Aug 31 15:27:16 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:27:16 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:27:16 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:27:16 bcik volumio[2747]: info: Initializing connection to go-librespot Websocket Aug 31 15:27:16 bcik volumio[2747]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:27:17 bcik volumio[2747]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Aug 31 15:27:17 bcik volumio[2747]: info: Updating MyVolumio device info Aug 31 15:27:17 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:27:17 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:27:17 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:27:17 bcik volumio[2747]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Aug 31 15:27:19 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 288. Aug 31 15:27:19 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:27:19 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:27:19 bcik go-librespot[3073]: go-librespot daemon starting... Aug 31 15:27:19 bcik go-librespot[3074]: time="2026-08-31T15:27:19+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:27:19 bcik go-librespot[3074]: time="2026-08-31T15:27:19+02:00" level=debug msg="app state loaded" Aug 31 15:27:19 bcik go-librespot[3074]: time="2026-08-31T15:27:19+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:27:19 bcik go-librespot[3074]: time="2026-08-31T15:27: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 31 15:27:19 bcik go-librespot[3074]: time="2026-08-31T15:27:19+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]" Aug 31 15:27:19 bcik go-librespot[3074]: time="2026-08-31T15:27:19+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]" Aug 31 15:27:19 bcik go-librespot[3074]: time="2026-08-31T15:27:19+02:00" level=info msg="zeroconf server listening on port 37857" Aug 31 15:27:19 bcik go-librespot[3074]: time="2026-08-31T15:27:19+02:00" level=debug msg="obtained new client token: AAFbI9xx+BKDY7r8hXGrgDFCBj0bdE1bv17tWJRcH9jI6PutLWa+m3pz+HbXKlENUvsI1cMeSIFwnXwukB1q+UYqOhqqD+ANvqidRVQmnGQQzIY29U9ohzJuQ7f48YVl1SKMwcXho2Jh2M5KZJySOS5ob4swH93B/NwrcwhAHIpdJBwWBBFsdR2hsDFi6TS+N+hUFs6NPAJQf/0+uJLqUCjCelUBQHc7+5GarE3JIAFz9s1hqmSkedM=" Aug 31 15:27:19 bcik go-librespot[3074]: time="2026-08-31T15:27: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" Aug 31 15:27:19 bcik go-librespot[3074]: time="2026-08-31T15:27: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" Aug 31 15:27:19 bcik go-librespot[3074]: time="2026-08-31T15:27:19+02:00" level=debug msg="connected to ap-gew4.spotify.com:80" Aug 31 15:27:19 bcik go-librespot[3074]: time="2026-08-31T15:27:19+02:00" level=debug msg="completed keyexchange" Aug 31 15:27:19 bcik go-librespot[3074]: time="2026-08-31T15:27:19+02:00" level=debug msg="completed challenge" Aug 31 15:27:19 bcik go-librespot[3074]: time="2026-08-31T15:27:19+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:27:19 bcik go-librespot[3074]: time="2026-08-31T15:27:19+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:27:19 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:27:19 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:27:19 bcik volumio[2747]: info: Initializing connection to go-librespot Websocket Aug 31 15:27:19 bcik volumio[2747]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:27:21 bcik volumio[2747]: info: MYVOLUMIO: Adding device Aug 31 15:27:21 bcik volumio[2747]: info: MYVOLUMIO: Evaluating Server Aug 31 15:27:22 bcik volumio[2747]: info: Initializing connection to go-librespot Websocket Aug 31 15:27:22 bcik volumio[2747]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:27:22 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 289. Aug 31 15:27:22 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:27:22 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:27:22 bcik go-librespot[3103]: go-librespot daemon starting... Aug 31 15:27:22 bcik go-librespot[3104]: time="2026-08-31T15:27:22+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:27:22 bcik go-librespot[3104]: time="2026-08-31T15:27:22+02:00" level=debug msg="app state loaded" Aug 31 15:27:22 bcik go-librespot[3104]: time="2026-08-31T15:27:22+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:27:22 bcik go-librespot[3104]: time="2026-08-31T15:27: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 15:27:22 bcik go-librespot[3104]: time="2026-08-31T15:27:22+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]" Aug 31 15:27:22 bcik go-librespot[3104]: time="2026-08-31T15:27:22+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]" Aug 31 15:27:22 bcik go-librespot[3104]: time="2026-08-31T15:27:22+02:00" level=info msg="zeroconf server listening on port 34517" Aug 31 15:27:22 bcik go-librespot[3104]: time="2026-08-31T15:27:22+02:00" level=debug msg="obtained new client token: AAH3ZwSsyjjXfWz8Fxu4nJhvusNOC7rk0GfdQ+D8+ogwy2oyoPRKSWTqiY7hisyOQ+NlpuHIezbJsgD7feU9pyFYtCBd3Fvq9d1mY+y77G/+9fSs/YyF2WiGiR9uTKZSgm0+vqps2YceVuxC07N0oqUmnSCtQSCaXUVt2COPYubxrUGA8sZm4R9R42Kg5qzedHLPTI9aBKmUIs6n6JrA3ffDPu2Doh3k+coOrAyNFvCnAg2/fRDoy+4=" Aug 31 15:27:22 bcik go-librespot[3104]: time="2026-08-31T15:27:22+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:27:23 bcik go-librespot[3104]: time="2026-08-31T15:27:23+02:00" level=debug msg="completed keyexchange" Aug 31 15:27:23 bcik go-librespot[3104]: time="2026-08-31T15:27:23+02:00" level=debug msg="completed challenge" Aug 31 15:27:23 bcik go-librespot[3104]: time="2026-08-31T15:27:23+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:27:23 bcik go-librespot[3104]: time="2026-08-31T15:27:23+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:27:23 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:27:23 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:27:23 bcik volumio[2747]: info: Setting Geolocation for MyVolumio to eu6 Aug 31 15:27:23 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:27:23 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:27:23 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:27:23 bcik volumio[2747]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Aug 31 15:27:24 bcik volumio[2747]: info: Updating MyVolumio device info Aug 31 15:27:24 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:27:24 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:27:24 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:27:24 bcik volumio[2747]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Aug 31 15:27:25 bcik volumio[2747]: info: Initializing connection to go-librespot Websocket Aug 31 15:27:25 bcik volumio[2747]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:27:26 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 290. Aug 31 15:27:26 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:27:26 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:27:26 bcik go-librespot[3128]: go-librespot daemon starting... Aug 31 15:27:26 bcik go-librespot[3129]: time="2026-08-31T15:27:26+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:27:26 bcik go-librespot[3129]: time="2026-08-31T15:27:26+02:00" level=debug msg="app state loaded" Aug 31 15:27:26 bcik go-librespot[3129]: time="2026-08-31T15:27:26+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:27:26 bcik go-librespot[3129]: time="2026-08-31T15:27: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-gew1.spotify.com:80]" Aug 31 15:27:26 bcik go-librespot[3129]: time="2026-08-31T15:27:26+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]" Aug 31 15:27:26 bcik go-librespot[3129]: time="2026-08-31T15:27:26+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]" Aug 31 15:27:26 bcik go-librespot[3129]: time="2026-08-31T15:27:26+02:00" level=info msg="zeroconf server listening on port 46079" Aug 31 15:27:26 bcik go-librespot[3129]: time="2026-08-31T15:27:26+02:00" level=debug msg="obtained new client token: AAGCZkphbSrizIwGaOJ5dwCln1FqJVHmq91KzBr1gLuyXTITOYi3qn05N79NFrixtmcIezMOQyhpjCwsAjpGbFWDWw3jNdDG7nEbPRQ8L4ErRg7+ezWvNhVC+DIpCaeAgGIq41eqfucNzRuLwFuQX4gdWbE3l3htkRMUDch6u2tfjtFSFnX7h+YtGwnA40ADK2fjxc3TLbqIjIVNmhM1BJfckiJYc8W6GpSJfzYuTEab0J51b5c885Q=" Aug 31 15:27:26 bcik go-librespot[3129]: time="2026-08-31T15:27:26+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" Aug 31 15:27:26 bcik go-librespot[3129]: time="2026-08-31T15:27:26+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Aug 31 15:27:26 bcik go-librespot[3129]: time="2026-08-31T15:27:26+02:00" level=debug msg="completed keyexchange" Aug 31 15:27:26 bcik go-librespot[3129]: time="2026-08-31T15:27:26+02:00" level=debug msg="completed challenge" Aug 31 15:27:26 bcik go-librespot[3129]: time="2026-08-31T15:27:26+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:27:26 bcik go-librespot[3129]: time="2026-08-31T15:27:26+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:27:26 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:27:26 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:27:28 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 31 15:27:28 bcik volumio[2747]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Aug 31 15:27:28 bcik volumio[2747]: info: CoreCommandRouter::volumioGetState Aug 31 15:27:28 bcik volumio[2747]: info: CorePlayQueue::getTrack 0 Aug 31 15:27:28 bcik volumio[2747]: info: Initializing connection to go-librespot Websocket Aug 31 15:27:28 bcik volumio[2747]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:27:29 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 291. Aug 31 15:27:29 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:27:29 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:27:29 bcik go-librespot[3138]: go-librespot daemon starting... Aug 31 15:27:29 bcik go-librespot[3139]: time="2026-08-31T15:27:29+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:27:29 bcik go-librespot[3139]: time="2026-08-31T15:27:29+02:00" level=debug msg="app state loaded" Aug 31 15:27:29 bcik go-librespot[3139]: time="2026-08-31T15:27:29+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:27:29 bcik go-librespot[3139]: time="2026-08-31T15:27: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 15:27:29 bcik go-librespot[3139]: time="2026-08-31T15:27:29+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]" Aug 31 15:27:29 bcik go-librespot[3139]: time="2026-08-31T15:27:29+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]" Aug 31 15:27:29 bcik go-librespot[3139]: time="2026-08-31T15:27:29+02:00" level=info msg="zeroconf server listening on port 42943" Aug 31 15:27:29 bcik go-librespot[3139]: time="2026-08-31T15:27:29+02:00" level=debug msg="obtained new client token: AAGAmjkFwT4aiysCqx7WoUmsUTXQvYUJNTAmOy4xjTEYdHQMPljmyDFNaB2G6ZjjuP+S4mRrQwoTuX9IvgiamE6PGNN6j96yMLxTcviPWqzxMkpblHF2Fw9tMoGIbrEQLJ03gXuT02WU2KhfxWWMzUf/q4paAqq6u5Sg3jS7R4Z7m1tkwNqlKr43bbuhQeilSw17KaPsMv4pEuoutKmZronoh03xxsgjauWTb4exq3Oo0qdGMbJQXqI=" Aug 31 15:27:29 bcik go-librespot[3139]: time="2026-08-31T15:27:29+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:27:30 bcik go-librespot[3139]: time="2026-08-31T15:27:30+02:00" level=debug msg="completed keyexchange" Aug 31 15:27:30 bcik go-librespot[3139]: time="2026-08-31T15:27:30+02:00" level=debug msg="completed challenge" Aug 31 15:27:30 bcik go-librespot[3139]: time="2026-08-31T15:27:30+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:27:30 bcik go-librespot[3139]: time="2026-08-31T15:27:30+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:27:30 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:27:30 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:27:31 bcik volumio[2747]: info: Initializing connection to go-librespot Websocket Aug 31 15:27:31 bcik volumio[2747]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:27:33 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 292. Aug 31 15:27:33 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:27:33 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:27:33 bcik go-librespot[3148]: go-librespot daemon starting... Aug 31 15:27:33 bcik go-librespot[3149]: time="2026-08-31T15:27:33+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:27:33 bcik go-librespot[3149]: time="2026-08-31T15:27:33+02:00" level=debug msg="app state loaded" Aug 31 15:27:33 bcik go-librespot[3149]: time="2026-08-31T15:27:33+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:27:33 bcik go-librespot[3149]: time="2026-08-31T15:27: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-gae2.spotify.com:80]" Aug 31 15:27:33 bcik go-librespot[3149]: time="2026-08-31T15:27:33+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]" Aug 31 15:27:33 bcik go-librespot[3149]: time="2026-08-31T15:27:33+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]" Aug 31 15:27:33 bcik go-librespot[3149]: time="2026-08-31T15:27:33+02:00" level=info msg="zeroconf server listening on port 39409" Aug 31 15:27:33 bcik go-librespot[3149]: time="2026-08-31T15:27:33+02:00" level=debug msg="obtained new client token: AAGsi8I1t1r8IPw1heBDC7Pcl4tYQhVT9cxIyQ9zrOyDNx6upiyWedaZ8arsPvVAmnCTfYrFk0P4+OnMSOpMDq7Tt+sY20f1NE9pVsosgVkK0y1vhLyDjnmBxMf6g8U5wsm2ApWPdhlNnwMHDHrY4njR5inHaviByr3zy43PM/w7+Y8IhW/+CQ2DEcp07A6Vq+aobjGQMaAYe8nv1HwobLzsXiYAZEcRsF+NyG8CQOaKfGZgaGEU3MY=" Aug 31 15:27:33 bcik go-librespot[3149]: time="2026-08-31T15:27:33+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:27:33 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:27:33 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:27:33 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Aug 31 15:27:33 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Aug 31 15:27:33 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Aug 31 15:27:33 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Aug 31 15:27:33 bcik volumio[2747]: info: CoreCommandRouter::volumioGetBrowseSources Aug 31 15:27:33 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 15:27:33 bcik go-librespot[3149]: time="2026-08-31T15:27:33+02:00" level=debug msg="completed keyexchange" Aug 31 15:27:33 bcik go-librespot[3149]: time="2026-08-31T15:27:33+02:00" level=debug msg="completed challenge" Aug 31 15:27:33 bcik volumio[2747]: error: MyVolumio Plugin failed to authenticate in a timely fashion Aug 31 15:27:33 bcik volumio[2747]: info: Completed starting MyVolumio Plugin Aug 31 15:27:33 bcik volumio[2747]: [Metrics] CommandRouter: 30s 806.60ms Aug 31 15:27:33 bcik volumio[2747]: info: CoreCommandRouter::volumiosetStartupVolume Aug 31 15:27:33 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 15:27:33 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:27:33 bcik volumio[2747]: info: CoreCommandRouter::Close All Modals sent Aug 31 15:27:33 bcik volumio[2747]: info: CoreCommandRouter::Close All Modals sent Aug 31 15:27:33 bcik go-librespot[3149]: time="2026-08-31T15:27:33+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:27:33 bcik go-librespot[3149]: time="2026-08-31T15:27:33+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:27:33 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:27:33 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:27:34 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 15:27:34 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 15:27:34 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 31 15:27:34 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Aug 31 15:27:34 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 31 15:27:34 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Aug 31 15:27:34 bcik volumio-remote-updater[962]: Test mode disabled Aug 31 15:27:34 bcik volumio-remote-updater[962]: Alpha mode disabled Aug 31 15:27:34 bcik volumio-remote-updater[962]: Alpha legacy test mode disabled Aug 31 15:27:34 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Aug 31 15:27:34 bcik volumio[2747]: info: Initializing connection to go-librespot Websocket Aug 31 15:27:34 bcik volumio[2747]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:27:34 bcik volumio[2747]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Aug 31 15:27:34 bcik volumio[2747]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Aug 31 15:27:37 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 293. Aug 31 15:27:37 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:27:37 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:27:37 bcik go-librespot[3179]: go-librespot daemon starting... Aug 31 15:27:37 bcik go-librespot[3180]: time="2026-08-31T15:27:37+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:27:37 bcik go-librespot[3180]: time="2026-08-31T15:27:37+02:00" level=debug msg="app state loaded" Aug 31 15:27:37 bcik go-librespot[3180]: time="2026-08-31T15:27:37+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:27:37 bcik go-librespot[3180]: time="2026-08-31T15:27:37+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]" Aug 31 15:27:37 bcik go-librespot[3180]: time="2026-08-31T15:27:37+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]" Aug 31 15:27:37 bcik go-librespot[3180]: time="2026-08-31T15:27:37+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]" Aug 31 15:27:37 bcik go-librespot[3180]: time="2026-08-31T15:27:37+02:00" level=info msg="zeroconf server listening on port 37037" Aug 31 15:27:37 bcik go-librespot[3180]: time="2026-08-31T15:27:37+02:00" level=debug msg="obtained new client token: AAHTW+6Be919oMvQW4PGk/vjnytT3sCHEqGVYUs2glyFvgxzVtx3uYXDgSezBwz3fJlsB4Ilzu2pXBPdElsk/XZrKJZjFgE5tND7tRkMPgmoJfUaYs6MVWtqVV8nHin0FVetjZIFM7DKAhWVw7/n5kw7j0OeDqNYX6+VtTyDk0m2hquW4boDO9219G70+NNvWqD1xu+2GRyaekpJ+oc3eoJsl2nzYba98gYgVHft0/lBweHxB0Zl" Aug 31 15:27:37 bcik go-librespot[3180]: time="2026-08-31T15:27:37+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:27:37 bcik go-librespot[3180]: time="2026-08-31T15:27:37+02:00" level=debug msg="completed keyexchange" Aug 31 15:27:37 bcik go-librespot[3180]: time="2026-08-31T15:27:37+02:00" level=debug msg="completed challenge" Aug 31 15:27:37 bcik go-librespot[3180]: time="2026-08-31T15:27:37+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:27:37 bcik go-librespot[3180]: time="2026-08-31T15:27:37+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:27:37 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:27:37 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:27:37 bcik volumio[2747]: info: Initializing connection to go-librespot Websocket Aug 31 15:27:37 bcik volumio[2747]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:27:40 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 294. Aug 31 15:27:40 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:27:40 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 15:27:40 bcik go-librespot[3189]: go-librespot daemon starting... Aug 31 15:27:40 bcik go-librespot[3190]: time="2026-08-31T15:27:40+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 15:27:40 bcik go-librespot[3190]: time="2026-08-31T15:27:40+02:00" level=debug msg="app state loaded" Aug 31 15:27:40 bcik go-librespot[3190]: time="2026-08-31T15:27:40+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 15:27:40 bcik go-librespot[3190]: time="2026-08-31T15:27: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 15:27:40 bcik go-librespot[3190]: time="2026-08-31T15:27:40+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]" Aug 31 15:27:40 bcik go-librespot[3190]: time="2026-08-31T15:27:40+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]" Aug 31 15:27:40 bcik go-librespot[3190]: time="2026-08-31T15:27:40+02:00" level=info msg="zeroconf server listening on port 43011" Aug 31 15:27:40 bcik go-librespot[3190]: time="2026-08-31T15:27:40+02:00" level=debug msg="obtained new client token: AAHcjczNIN2Bp7is3DPEQlOJ3Y5wVZE5SNUX0nvF+Au9RDpQ7qGEK3xg2SzoN+g6JSTw+t3tw27SsS0qr9DMcFPC6PLA2GiA+T3zlbBnGnuL4SY0MJ8oOE2ddZzYmH2fHFDpHalb9m+cpOnO5JpCKawQNfa9U05kygEUqTLo5222I+S9J2NsQYdDFrJnGyRFDTXRpgmvxAeOTQSSr+uEfkWztlyAAmOt3fnluGsEQQr4ZHVbxiwlkUs=" Aug 31 15:27:40 bcik go-librespot[3190]: time="2026-08-31T15:27:40+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 15:27:40 bcik volumio[2747]: info: BOOT COMPLETED Aug 31 15:27:40 bcik go-librespot[3190]: time="2026-08-31T15:27:40+02:00" level=debug msg="completed keyexchange" Aug 31 15:27:40 bcik go-librespot[3190]: time="2026-08-31T15:27:40+02:00" level=debug msg="completed challenge" Aug 31 15:27:40 bcik volumio[2747]: info: Initializing connection to go-librespot Websocket Aug 31 15:27:40 bcik go-librespot[3190]: time="2026-08-31T15:27:40+02:00" level=debug msg="new websocket client" Aug 31 15:27:40 bcik volumio[2747]: info: Connection to go-librespot Websocket established Aug 31 15:27:40 bcik go-librespot[3190]: time="2026-08-31T15:27:40+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 15:27:40 bcik go-librespot[3190]: time="2026-08-31T15:27:40+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 15:27:40 bcik volumio[2747]: info: Connection to go-librespot Websocket closed Aug 31 15:27:40 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 15:27:40 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 15:27:43 bcik volumio[2747]: info: Getting Spotify volume Aug 31 15:27:43 bcik volumio[2747]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 15:27:43 bcik volumio[2747]: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 15:27:43 bcik volumio[2747]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Aug 31 15:27:43 bcik volumio[2747]: errno: -111, Aug 31 15:27:43 bcik volumio[2747]: code: 'ECONNREFUSED', Aug 31 15:27:43 bcik volumio[2747]: syscall: 'connect', Aug 31 15:27:43 bcik volumio[2747]: address: '127.0.0.1', Aug 31 15:27:43 bcik volumio[2747]: port: 9879, Aug 31 15:27:43 bcik volumio[2747]: response: undefined Aug 31 15:27:43 bcik volumio[2747]: } Aug 31 15:27:43 bcik volumio[2747]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 15:27:43 bcik sudo[3227]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-31 15:26' Aug 31 15:27:43 bcik sudo[3227]: 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"