Oct 12 23:34:01 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 438. Oct 12 23:34:01 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 23:34:01 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 23:34:01 bcik go-librespot[3936]: go-librespot daemon starting... Oct 12 23:34:01 bcik go-librespot[3937]: time="2026-10-12T23:34:01+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 23:34:01 bcik go-librespot[3937]: time="2026-10-12T23:34:01+02:00" level=debug msg="app state loaded" Oct 12 23:34:01 bcik go-librespot[3937]: time="2026-10-12T23:34:01+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 23:34:01 bcik go-librespot[3937]: time="2026-10-12T23:34:01+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 12 23:34:01 bcik go-librespot[3937]: time="2026-10-12T23:34:01+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 12 23:34:01 bcik go-librespot[3937]: time="2026-10-12T23:34:01+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 12 23:34:01 bcik go-librespot[3937]: time="2026-10-12T23:34:01+02:00" level=info msg="zeroconf server listening on port 35937" Oct 12 23:34:01 bcik go-librespot[3937]: time="2026-10-12T23:34:01+02:00" level=debug msg="obtained new client token: AAGaD/mCnn0rtMUyTt9CoWj+skKY3yzH3b9llJrE2WlhgYpMzzgNmUG4Cy2xtIz3JcxucHZ0gH1TdK0snutkaDfVB+KQtiQjVESqy7kB8H/GPVVeIhHmWATMqMwP8i5gixfWjWTPdTBNJpZrpR+dWCJoZ8IWEhOoVum9m/XNqS/IU2LUyXn+2qSN36YJIoz9GSiPaYqMPjOO55zeSw9xHpQ31dHMKEy/xOyexzOTwfBinHKJZxYA" Oct 12 23:34:01 bcik go-librespot[3937]: time="2026-10-12T23:34:01+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 23:34:01 bcik go-librespot[3937]: time="2026-10-12T23:34:01+02:00" level=debug msg="completed keyexchange" Oct 12 23:34:01 bcik go-librespot[3937]: time="2026-10-12T23:34:01+02:00" level=debug msg="completed challenge" Oct 12 23:34:01 bcik go-librespot[3937]: time="2026-10-12T23:34:01+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 23:34:01 bcik go-librespot[3937]: time="2026-10-12T23:34:01+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 23:34:01 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 23:34:01 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 23:34:02 bcik volumio[3307]: info: Initializing connection to go-librespot Websocket Oct 12 23:34:02 bcik volumio[3307]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 23:34:04 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 439. Oct 12 23:34:04 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 23:34:04 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 23:34:04 bcik go-librespot[3946]: go-librespot daemon starting... Oct 12 23:34:04 bcik go-librespot[3947]: time="2026-10-12T23:34:04+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 23:34:04 bcik go-librespot[3947]: time="2026-10-12T23:34:04+02:00" level=debug msg="app state loaded" Oct 12 23:34:04 bcik go-librespot[3947]: time="2026-10-12T23:34:04+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 23:34:04 bcik go-librespot[3947]: time="2026-10-12T23:34: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 12 23:34:04 bcik go-librespot[3947]: time="2026-10-12T23:34:04+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 12 23:34:04 bcik go-librespot[3947]: time="2026-10-12T23:34:04+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 12 23:34:04 bcik go-librespot[3947]: time="2026-10-12T23:34:04+02:00" level=info msg="zeroconf server listening on port 33507" Oct 12 23:34:04 bcik go-librespot[3947]: time="2026-10-12T23:34:04+02:00" level=debug msg="obtained new client token: AAFL3rqnuG3D/SFBUGWWnf9XSumGweq4p+mFLT9Zw+fX9EXMbEuDBAj/1WaQ64RILy9K2e0QPCg+YJnUOWk7EhjsnCqtDhOQvBKVquwTo7u6ejE2G0pbU3ZNfOG23P2Qu4VvlP8VGMUljfId/Y54eZKCp312VXJThfRhx1PYcpi3uvaMsC+KJfusaLwgZXcAfQlM2s7lw8bOb4iyL6Cnr9f6W9WrzOVtC7mn1j/ig5uF3vWvhbsJDUk=" Oct 12 23:34:04 bcik go-librespot[3947]: time="2026-10-12T23:34:04+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 23:34:04 bcik go-librespot[3947]: time="2026-10-12T23:34:04+02:00" level=debug msg="completed keyexchange" Oct 12 23:34:04 bcik go-librespot[3947]: time="2026-10-12T23:34:04+02:00" level=debug msg="completed challenge" Oct 12 23:34:04 bcik go-librespot[3947]: time="2026-10-12T23:34:04+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 23:34:04 bcik go-librespot[3947]: time="2026-10-12T23:34:04+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 23:34:04 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 23:34:04 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 23:34:05 bcik volumio[3307]: info: Initializing connection to go-librespot Websocket Oct 12 23:34:05 bcik volumio[3307]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 23:34:08 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 440. Oct 12 23:34:08 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 23:34:08 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 23:34:08 bcik go-librespot[3971]: go-librespot daemon starting... Oct 12 23:34:08 bcik go-librespot[3972]: time="2026-10-12T23:34:08+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 23:34:08 bcik go-librespot[3972]: time="2026-10-12T23:34:08+02:00" level=debug msg="app state loaded" Oct 12 23:34:08 bcik go-librespot[3972]: time="2026-10-12T23:34:08+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 23:34:08 bcik go-librespot[3972]: time="2026-10-12T23:34:08+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Oct 12 23:34:08 bcik go-librespot[3972]: time="2026-10-12T23:34:08+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Oct 12 23:34:08 bcik go-librespot[3972]: time="2026-10-12T23:34:08+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Oct 12 23:34:08 bcik go-librespot[3972]: time="2026-10-12T23:34:08+02:00" level=info msg="zeroconf server listening on port 45257" Oct 12 23:34:08 bcik go-librespot[3972]: time="2026-10-12T23:34:08+02:00" level=debug msg="obtained new client token: AAGVT6ULipdzvQHQUC4aUZLT0hjRu/1zZFigAiIQvms/Djq7aMJA/5Oh4lt7vtjU6A3TkoLJ/Fiop1YxCGJ9tV3JqHSOjq8CW2YEJqqbrxfeUhw/yTBfVDql5//NYS3XVBwg4EDSi3g6QvF/HPLxHGnnvRdPK5Fmo1whrG5RPsg3mjzNxDlEFVHJzRctblPfpx6E9iIoQKfxBQXFFIKkCV/4iZtNhBAacwbkU30ri0oyeBlpAyXH" Oct 12 23:34:08 bcik go-librespot[3972]: time="2026-10-12T23:34:08+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 23:34:08 bcik go-librespot[3972]: time="2026-10-12T23:34:08+02:00" level=debug msg="completed keyexchange" Oct 12 23:34:08 bcik go-librespot[3972]: time="2026-10-12T23:34:08+02:00" level=debug msg="completed challenge" Oct 12 23:34:08 bcik go-librespot[3972]: time="2026-10-12T23:34:08+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 23:34:08 bcik go-librespot[3972]: time="2026-10-12T23:34:08+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 23:34:08 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 23:34:08 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 23:34:08 bcik volumio[3307]: info: Initializing connection to go-librespot Websocket Oct 12 23:34:08 bcik volumio[3307]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 23:34:11 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 441. Oct 12 23:34:11 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 23:34:11 bcik volumio[3307]: info: Initializing connection to go-librespot Websocket Oct 12 23:34:11 bcik volumio[3307]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 23:34:11 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 23:34:11 bcik go-librespot[3981]: go-librespot daemon starting... Oct 12 23:34:11 bcik go-librespot[3982]: time="2026-10-12T23:34:11+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 23:34:11 bcik go-librespot[3982]: time="2026-10-12T23:34:11+02:00" level=debug msg="app state loaded" Oct 12 23:34:11 bcik go-librespot[3982]: time="2026-10-12T23:34:11+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 23:34:11 bcik go-librespot[3982]: time="2026-10-12T23:34: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-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 12 23:34:11 bcik go-librespot[3982]: time="2026-10-12T23:34:11+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 12 23:34:11 bcik go-librespot[3982]: time="2026-10-12T23:34:11+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 12 23:34:11 bcik go-librespot[3982]: time="2026-10-12T23:34:11+02:00" level=info msg="zeroconf server listening on port 44209" Oct 12 23:34:11 bcik go-librespot[3982]: time="2026-10-12T23:34:11+02:00" level=debug msg="obtained new client token: AAH2MnwoPzG2vznAb0caUYKsf38MZ37mZly/F7n/uHGPOchvSi7IyFZcmg5ZkFtbnM3k/LsWsXKsNc8aFzSVVIzvI4fZ6whJ5wlRXJJbFErwQd1sN/dsmpnS9r4/Zh64mOHE4Nk5jTliWAniRZepuKe7yGTQ1CFlFJL2k9/vEo+jKOtFL+p8VbcfnkCLUA6twBmnr2PtY6HtjlEMoiMMteqcYLFSOQRGgAduqOrws7OOstxQlzq/jqQ=" Oct 12 23:34:11 bcik go-librespot[3982]: time="2026-10-12T23:34:11+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 23:34:11 bcik go-librespot[3982]: time="2026-10-12T23:34:11+02:00" level=debug msg="completed keyexchange" Oct 12 23:34:11 bcik go-librespot[3982]: time="2026-10-12T23:34:11+02:00" level=debug msg="completed challenge" Oct 12 23:34:11 bcik go-librespot[3982]: time="2026-10-12T23:34:11+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 23:34:11 bcik go-librespot[3982]: time="2026-10-12T23:34:11+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 23:34:11 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 23:34:11 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 23:34:14 bcik volumio[3307]: info: Initializing connection to go-librespot Websocket Oct 12 23:34:14 bcik volumio[3307]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 23:34:15 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 442. Oct 12 23:34:15 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 23:34:15 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 23:34:15 bcik go-librespot[3991]: go-librespot daemon starting... Oct 12 23:34:15 bcik go-librespot[3992]: time="2026-10-12T23:34:15+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 23:34:15 bcik go-librespot[3992]: time="2026-10-12T23:34:15+02:00" level=debug msg="app state loaded" Oct 12 23:34:15 bcik go-librespot[3992]: time="2026-10-12T23:34:15+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 23:34:15 bcik go-librespot[3992]: time="2026-10-12T23:34: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]" Oct 12 23:34:15 bcik go-librespot[3992]: time="2026-10-12T23:34: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]" Oct 12 23:34:15 bcik go-librespot[3992]: time="2026-10-12T23:34: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]" Oct 12 23:34:15 bcik go-librespot[3992]: time="2026-10-12T23:34:15+02:00" level=info msg="zeroconf server listening on port 35779" Oct 12 23:34:15 bcik go-librespot[3992]: time="2026-10-12T23:34:15+02:00" level=debug msg="obtained new client token: AAHAr+xgbd7r17eGnhbJS9Q4IU4uxo8VoO99wohyaSx3mXllKyVQNZ6D/QCVf7VcTwrK64q+iXlSw+/UtJCqTdOOjPDKy+OAe4ZswAz0wdbMv6h/hIdfyyxFMV5ZuytO/5QcQ1KVH0n0ZyTXw/iyDc7nU79Ur1zLrQm2FG4/UKICkxUa4rGYhYolWxNRpGZrnt13974STrYD2LUFLl9exz1oC2AhEiDfsSO8P3/ToLLlYlJbREBn" Oct 12 23:34:15 bcik go-librespot[3992]: time="2026-10-12T23:34:15+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 23:34:15 bcik go-librespot[3992]: time="2026-10-12T23:34:15+02:00" level=debug msg="completed keyexchange" Oct 12 23:34:15 bcik go-librespot[3992]: time="2026-10-12T23:34:15+02:00" level=debug msg="completed challenge" Oct 12 23:34:15 bcik go-librespot[3992]: time="2026-10-12T23:34:15+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 23:34:15 bcik go-librespot[3992]: time="2026-10-12T23:34:15+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 23:34:15 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 23:34:15 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 23:34:17 bcik volumio[3307]: info: Initializing connection to go-librespot Websocket Oct 12 23:34:17 bcik volumio[3307]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 23:34:18 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 443. Oct 12 23:34:18 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 23:34:18 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 23:34:18 bcik go-librespot[4015]: go-librespot daemon starting... Oct 12 23:34:18 bcik go-librespot[4016]: time="2026-10-12T23:34:18+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 23:34:18 bcik go-librespot[4016]: time="2026-10-12T23:34:18+02:00" level=debug msg="app state loaded" Oct 12 23:34:18 bcik go-librespot[4016]: time="2026-10-12T23:34:18+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 23:34:18 bcik go-librespot[4016]: time="2026-10-12T23:34:18+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 12 23:34:18 bcik go-librespot[4016]: time="2026-10-12T23:34:18+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 12 23:34:18 bcik go-librespot[4016]: time="2026-10-12T23:34:18+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 12 23:34:18 bcik go-librespot[4016]: time="2026-10-12T23:34:18+02:00" level=info msg="zeroconf server listening on port 43391" Oct 12 23:34:18 bcik go-librespot[4016]: time="2026-10-12T23:34:18+02:00" level=debug msg="obtained new client token: AAEaTuJph3YgdcCuarEE8KubqHHyDhe4/MjawfONTorZvoYhyVsbVHKIEdkZ48METxZvns7XJhXcnrmOF1Aoe4KKYsdueK3WGxNGmSF6raJD9MJNz+vxXIcjA4/OW9XMIUaD2pi7ZvY0mL51ahFW5QB0amRKHopi0mFV4MGeiWT3QdACIZtqBN2vLw5jvsSxiYsMtGj8/Yez2pPA4/rF0u4qjC/GyiKGyxKQSKW/eruQ0OZhlFQobvM=" Oct 12 23:34:18 bcik go-librespot[4016]: time="2026-10-12T23:34:18+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Oct 12 23:34:18 bcik go-librespot[4016]: time="2026-10-12T23:34:18+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Oct 12 23:34:18 bcik go-librespot[4016]: time="2026-10-12T23:34:18+02:00" level=debug msg="completed keyexchange" Oct 12 23:34:18 bcik go-librespot[4016]: time="2026-10-12T23:34:18+02:00" level=debug msg="completed challenge" Oct 12 23:34:18 bcik go-librespot[4016]: time="2026-10-12T23:34:18+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 23:34:18 bcik go-librespot[4016]: time="2026-10-12T23:34:18+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 23:34:18 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 23:34:18 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 23:34:20 bcik volumio[3307]: info: Initializing connection to go-librespot Websocket Oct 12 23:34:20 bcik volumio[3307]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 23:34:22 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 444. Oct 12 23:34:22 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 23:34:22 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 23:34:22 bcik go-librespot[4025]: go-librespot daemon starting... Oct 12 23:34:22 bcik go-librespot[4026]: time="2026-10-12T23:34:22+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 23:34:22 bcik go-librespot[4026]: time="2026-10-12T23:34:22+02:00" level=debug msg="app state loaded" Oct 12 23:34:22 bcik go-librespot[4026]: time="2026-10-12T23:34:22+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 23:34:22 bcik go-librespot[4026]: time="2026-10-12T23:34:22+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 12 23:34:22 bcik go-librespot[4026]: time="2026-10-12T23:34:22+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 12 23:34:22 bcik go-librespot[4026]: time="2026-10-12T23:34:22+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 12 23:34:22 bcik go-librespot[4026]: time="2026-10-12T23:34:22+02:00" level=info msg="zeroconf server listening on port 38139" Oct 12 23:34:22 bcik go-librespot[4026]: time="2026-10-12T23:34:22+02:00" level=debug msg="obtained new client token: AAHS8bI73CI0qfeCBNrrjdHVattBNetxM4n5+aWHXrvorq1qI/1dGbtiOfw9UvC5SxCcJDcwdbpvbpKRLsBioO+ZgRJnaSpO14FWOAIH4FHAmrORIYGqc4iqU+TNOu7/jiCMWPS+13h4qJ9Lf2eQzkNTrSMyDXz5mik8tZwvxLns7RItNzLoOGpagJsCc4xdnFEvxRvw/Pv2+wT193kwvwCc1tvUubxfOiWwcXDKXxJr8N1yCGHB" Oct 12 23:34:22 bcik go-librespot[4026]: time="2026-10-12T23:34:22+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 23:34:22 bcik go-librespot[4026]: time="2026-10-12T23:34:22+02:00" level=debug msg="completed keyexchange" Oct 12 23:34:22 bcik go-librespot[4026]: time="2026-10-12T23:34:22+02:00" level=debug msg="completed challenge" Oct 12 23:34:22 bcik go-librespot[4026]: time="2026-10-12T23:34:22+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 23:34:22 bcik go-librespot[4026]: time="2026-10-12T23:34:22+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 23:34:22 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 23:34:22 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 23:34:23 bcik volumio[3307]: info: Initializing connection to go-librespot Websocket Oct 12 23:34:23 bcik volumio[3307]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 23:34:25 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 445. Oct 12 23:34:25 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 23:34:25 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 23:34:25 bcik go-librespot[4035]: go-librespot daemon starting... Oct 12 23:34:25 bcik go-librespot[4036]: time="2026-10-12T23:34:25+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 23:34:25 bcik go-librespot[4036]: time="2026-10-12T23:34:25+02:00" level=debug msg="app state loaded" Oct 12 23:34:25 bcik go-librespot[4036]: time="2026-10-12T23:34:25+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 23:34:25 bcik go-librespot[4036]: time="2026-10-12T23:34:25+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 12 23:34:25 bcik go-librespot[4036]: time="2026-10-12T23:34:25+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 12 23:34:25 bcik go-librespot[4036]: time="2026-10-12T23:34:25+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 12 23:34:25 bcik go-librespot[4036]: time="2026-10-12T23:34:25+02:00" level=info msg="zeroconf server listening on port 43153" Oct 12 23:34:25 bcik go-librespot[4036]: time="2026-10-12T23:34:25+02:00" level=debug msg="obtained new client token: AAHvLu/N570jAmSVmqcaHvp6J5AwXvhuALwAaTEd6KY9b3hm0Qow2ppW129pxB/wQV4Qd9eZ7YJy5GBvFaWbQdaZn6Gv8JTjpE0jRmfydK/sZT0Izi+T5i2AL8UrYjidTe6P9w2W+cy9cIK1iht1q25uAX1hRLtbgdnIC+VDIuLJ3c8N53cBCL7zHeTvF/nmHrYModBnOQCcQqY98Crq5lRNfTFu9nHW+E36d3jVAkA/fo6mFZYbwJw=" Oct 12 23:34:25 bcik go-librespot[4036]: time="2026-10-12T23:34:25+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 23:34:25 bcik go-librespot[4036]: time="2026-10-12T23:34:25+02:00" level=debug msg="completed keyexchange" Oct 12 23:34:25 bcik go-librespot[4036]: time="2026-10-12T23:34:25+02:00" level=debug msg="completed challenge" Oct 12 23:34:25 bcik go-librespot[4036]: time="2026-10-12T23:34:25+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 23:34:25 bcik go-librespot[4036]: time="2026-10-12T23:34:25+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 23:34:25 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 23:34:25 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 23:34:26 bcik volumio[3307]: info: Initializing connection to go-librespot Websocket Oct 12 23:34:26 bcik volumio[3307]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 23:34:29 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 446. Oct 12 23:34:29 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 23:34:29 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 23:34:29 bcik go-librespot[4060]: go-librespot daemon starting... Oct 12 23:34:29 bcik go-librespot[4061]: time="2026-10-12T23:34:29+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 23:34:29 bcik go-librespot[4061]: time="2026-10-12T23:34:29+02:00" level=debug msg="app state loaded" Oct 12 23:34:29 bcik go-librespot[4061]: time="2026-10-12T23:34:29+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 23:34:29 bcik go-librespot[4061]: time="2026-10-12T23:34:29+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 12 23:34:29 bcik go-librespot[4061]: time="2026-10-12T23:34:29+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 12 23:34:29 bcik go-librespot[4061]: time="2026-10-12T23:34:29+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 12 23:34:29 bcik go-librespot[4061]: time="2026-10-12T23:34:29+02:00" level=info msg="zeroconf server listening on port 33035" Oct 12 23:34:29 bcik go-librespot[4061]: time="2026-10-12T23:34:29+02:00" level=debug msg="obtained new client token: AAE6bG3uNhK5RrYkIUYRskKLqnbek3Z2f1STFmZO/Nt5vnOTN+CRDesuooERSrTyTCTisBCjr9ca2OLj6BKWOVNwPVKHW8Iv1f5ouUdRaK3XPAUjKbZy8YU60sz8NQyzbVeo5Wy2MAHQTyEnY+UkuHmmCmDl99chg+3IcMYRn9ZaPSyAfbmpeFmxm2xBG+V1PO1vac1QhXNmNEiOvGqQHJqAsUKWRxO/vr4dY1uJLdOCcOT7ihuj" Oct 12 23:34:29 bcik go-librespot[4061]: time="2026-10-12T23:34:29+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 23:34:29 bcik go-librespot[4061]: time="2026-10-12T23:34:29+02:00" level=debug msg="completed keyexchange" Oct 12 23:34:29 bcik go-librespot[4061]: time="2026-10-12T23:34:29+02:00" level=debug msg="completed challenge" Oct 12 23:34:29 bcik go-librespot[4061]: time="2026-10-12T23:34:29+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 23:34:29 bcik go-librespot[4061]: time="2026-10-12T23:34:29+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 23:34:29 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 23:34:29 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 23:34:29 bcik volumio[3307]: info: Initializing connection to go-librespot Websocket Oct 12 23:34:29 bcik volumio[3307]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 23:34:32 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 447. Oct 12 23:34:32 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 23:34:32 bcik volumio[3307]: info: Initializing connection to go-librespot Websocket Oct 12 23:34:32 bcik volumio[3307]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 23:34:32 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 23:34:32 bcik go-librespot[4070]: go-librespot daemon starting... Oct 12 23:34:32 bcik go-librespot[4071]: time="2026-10-12T23:34:32+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 23:34:32 bcik go-librespot[4071]: time="2026-10-12T23:34:32+02:00" level=debug msg="app state loaded" Oct 12 23:34:32 bcik go-librespot[4071]: time="2026-10-12T23:34:32+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 23:34:32 bcik go-librespot[4071]: time="2026-10-12T23:34:32+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 12 23:34:32 bcik go-librespot[4071]: time="2026-10-12T23:34:32+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 12 23:34:32 bcik go-librespot[4071]: time="2026-10-12T23:34:32+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 12 23:34:32 bcik go-librespot[4071]: time="2026-10-12T23:34:32+02:00" level=info msg="zeroconf server listening on port 33845" Oct 12 23:34:32 bcik go-librespot[4071]: time="2026-10-12T23:34:32+02:00" level=debug msg="obtained new client token: AAGLuUIQTU4gitcpXuLhZ08yI/CP2wubaSm+FiOnPJHVBUVZEQSQRfFOM8VndqOty3mMM51vMlcImH/G8SK8cN8BHGKrHWsdhRiZo15IBbMOZInIE6NFACTpmWiaStlwLbufAs+abEkM86qxllRQBOTmbeTQy8RUI07EpPnfv1zE/iH+67xP6clzbN2SWHaH4QgMav9kQtjDGOjHmqWXzt8thv6/M33oxBg6UEx4DuB0ACYVzBDgK+8=" Oct 12 23:34:32 bcik go-librespot[4071]: time="2026-10-12T23:34:32+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Oct 12 23:34:32 bcik go-librespot[4071]: time="2026-10-12T23:34:32+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Oct 12 23:34:32 bcik go-librespot[4071]: time="2026-10-12T23:34:32+02:00" level=debug msg="completed keyexchange" Oct 12 23:34:32 bcik go-librespot[4071]: time="2026-10-12T23:34:32+02:00" level=debug msg="completed challenge" Oct 12 23:34:32 bcik go-librespot[4071]: time="2026-10-12T23:34:32+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 23:34:32 bcik go-librespot[4071]: time="2026-10-12T23:34:32+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 23:34:32 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 23:34:32 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 23:34:35 bcik volumio[3307]: info: Initializing connection to go-librespot Websocket Oct 12 23:34:35 bcik volumio[3307]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 23:34:36 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 448. Oct 12 23:34:36 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 23:34:36 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 23:34:36 bcik go-librespot[4081]: go-librespot daemon starting... Oct 12 23:34:36 bcik go-librespot[4082]: time="2026-10-12T23:34:36+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 23:34:36 bcik go-librespot[4082]: time="2026-10-12T23:34:36+02:00" level=debug msg="app state loaded" Oct 12 23:34:36 bcik go-librespot[4082]: time="2026-10-12T23:34:36+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 23:34:36 bcik go-librespot[4082]: time="2026-10-12T23:34:36+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 12 23:34:36 bcik go-librespot[4082]: time="2026-10-12T23:34:36+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 12 23:34:36 bcik go-librespot[4082]: time="2026-10-12T23:34:36+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 12 23:34:36 bcik go-librespot[4082]: time="2026-10-12T23:34:36+02:00" level=info msg="zeroconf server listening on port 43467" Oct 12 23:34:36 bcik go-librespot[4082]: time="2026-10-12T23:34:36+02:00" level=debug msg="obtained new client token: AAGOvLFRtkSSNV0KupfVNSAhqnBUqXznkre/70jIZ+rang004JSGc3yO+nApevPV4HBI5wkBT8HTzK9vhr2KKqri+Kr6N8wTHmqUd1gimBBPCcgrsXl6QiU13N70gyuxrc52f8wnG0c3MymhssxJek8+mujsmwx1gVSXhMrJ/XxVNl5L5U4wXTP8SAMkaEa1rpaEwCZYpaCzH46Ng3ER3MAmXI33x8mB8oUmfMoJs7gEKQqg/zM8" Oct 12 23:34:36 bcik go-librespot[4082]: time="2026-10-12T23:34:36+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 23:34:36 bcik go-librespot[4082]: time="2026-10-12T23:34:36+02:00" level=debug msg="completed keyexchange" Oct 12 23:34:36 bcik go-librespot[4082]: time="2026-10-12T23:34:36+02:00" level=debug msg="completed challenge" Oct 12 23:34:36 bcik go-librespot[4082]: time="2026-10-12T23:34:36+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 23:34:36 bcik go-librespot[4082]: time="2026-10-12T23:34:36+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 23:34:36 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 23:34:36 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 23:34:38 bcik volumio[3307]: info: Initializing connection to go-librespot Websocket Oct 12 23:34:38 bcik volumio[3307]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 23:34:39 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 449. Oct 12 23:34:39 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 23:34:39 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 23:34:39 bcik go-librespot[4105]: go-librespot daemon starting... Oct 12 23:34:39 bcik go-librespot[4106]: time="2026-10-12T23:34:39+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 23:34:39 bcik go-librespot[4106]: time="2026-10-12T23:34:39+02:00" level=debug msg="app state loaded" Oct 12 23:34:39 bcik go-librespot[4106]: time="2026-10-12T23:34:39+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 23:34:39 bcik go-librespot[4106]: time="2026-10-12T23:34:39+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 12 23:34:39 bcik go-librespot[4106]: time="2026-10-12T23:34:39+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 12 23:34:39 bcik go-librespot[4106]: time="2026-10-12T23:34:39+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 12 23:34:39 bcik go-librespot[4106]: time="2026-10-12T23:34:39+02:00" level=info msg="zeroconf server listening on port 35547" Oct 12 23:34:39 bcik go-librespot[4106]: time="2026-10-12T23:34:39+02:00" level=debug msg="obtained new client token: AAHjQPWfW4WkykLbA1L1jvRrZcJnCl8yjsN2gyUjjKZjyCVtJmyuxhRFQvVvxLRk+A4OYef6SXuG8o+f7RQjDsNYP0+5Zzqlf+MEQQQIW/dhVa+ofJiAWPKtCFFmdS9URAQ/3a7FitUIFRkHen+UmJ7rsJFHpbBR4YJRRVhbaGfeJvRcdlLW1PnphGfwgUC42JHdbivmty3VVRFQGKfsQWnzGOzo5fefwHbqgaq5zWEQ8S27ClxOnLE=" Oct 12 23:34:39 bcik go-librespot[4106]: time="2026-10-12T23:34:39+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 23:34:39 bcik go-librespot[4106]: time="2026-10-12T23:34:39+02:00" level=debug msg="completed keyexchange" Oct 12 23:34:39 bcik go-librespot[4106]: time="2026-10-12T23:34:39+02:00" level=debug msg="completed challenge" Oct 12 23:34:39 bcik go-librespot[4106]: time="2026-10-12T23:34:39+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 23:34:39 bcik go-librespot[4106]: time="2026-10-12T23:34:39+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 23:34:39 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 23:34:39 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 23:34:41 bcik volumio[3307]: info: Initializing connection to go-librespot Websocket Oct 12 23:34:41 bcik volumio[3307]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 23:34:43 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 450. Oct 12 23:34:43 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 23:34:43 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 23:34:43 bcik go-librespot[4115]: go-librespot daemon starting... Oct 12 23:34:43 bcik go-librespot[4116]: time="2026-10-12T23:34:43+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 23:34:43 bcik go-librespot[4116]: time="2026-10-12T23:34:43+02:00" level=debug msg="app state loaded" Oct 12 23:34:43 bcik go-librespot[4116]: time="2026-10-12T23:34:43+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 23:34:43 bcik go-librespot[4116]: time="2026-10-12T23:34:43+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Oct 12 23:34:43 bcik go-librespot[4116]: time="2026-10-12T23:34:43+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Oct 12 23:34:43 bcik go-librespot[4116]: time="2026-10-12T23:34:43+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Oct 12 23:34:43 bcik go-librespot[4116]: time="2026-10-12T23:34:43+02:00" level=info msg="zeroconf server listening on port 35097" Oct 12 23:34:43 bcik go-librespot[4116]: time="2026-10-12T23:34:43+02:00" level=debug msg="obtained new client token: AAHFBTSnkj0zOr3YZ+jpSPHvI/+BehKKU0yhKnv6kultdPUBaZzIAABnTK28mcECRh16e4r7qilKkwidO5kKQb8jq0PveeCZ92g21eL2BlozNIop5rv8klmeD9CEyKdSSt9vQURMaYM0BJel20blNYYhU0Jpm+Iky+oBAIA9myb6voSGZ+HLTkbJ763wtSVXi5bRchh6/fniE7nmlcigBJcFKi7hwDTq9QTsmHpu90pRyatUdS/p" Oct 12 23:34:43 bcik go-librespot[4116]: time="2026-10-12T23:34:43+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 23:34:43 bcik go-librespot[4116]: time="2026-10-12T23:34:43+02:00" level=debug msg="completed keyexchange" Oct 12 23:34:43 bcik go-librespot[4116]: time="2026-10-12T23:34:43+02:00" level=debug msg="completed challenge" Oct 12 23:34:43 bcik go-librespot[4116]: time="2026-10-12T23:34:43+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 23:34:43 bcik go-librespot[4116]: time="2026-10-12T23:34:43+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 23:34:43 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 23:34:43 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 23:34:44 bcik volumio[3307]: info: Initializing connection to go-librespot Websocket Oct 12 23:34:44 bcik volumio[3307]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 23:34:46 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 451. Oct 12 23:34:46 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 23:34:46 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 23:34:46 bcik go-librespot[4140]: go-librespot daemon starting... Oct 12 23:34:46 bcik go-librespot[4141]: time="2026-10-12T23:34:46+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 23:34:46 bcik go-librespot[4141]: time="2026-10-12T23:34:46+02:00" level=debug msg="app state loaded" Oct 12 23:34:46 bcik go-librespot[4141]: time="2026-10-12T23:34:46+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 23:34:46 bcik go-librespot[4141]: time="2026-10-12T23:34:46+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 12 23:34:46 bcik go-librespot[4141]: time="2026-10-12T23:34:46+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 12 23:34:46 bcik go-librespot[4141]: time="2026-10-12T23:34:46+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 12 23:34:46 bcik go-librespot[4141]: time="2026-10-12T23:34:46+02:00" level=info msg="zeroconf server listening on port 43779" Oct 12 23:34:46 bcik go-librespot[4141]: time="2026-10-12T23:34:46+02:00" level=debug msg="obtained new client token: AAEo8Xauwm9/3hGwuveqZGXeLciuNU+E+TbCEMh7Mkt2e5nNrvjgC/WIX3c1YoJ2rpmkh2r8bQ4ZMhsnuOeqzdwrdql5jW0/n2UeN33f8QGXVo1qc5sViYiSQ8qwavD/BCy4wzMdkrqW6HZuTRm15oEk1T5+4Pf4jsby2/IxS5xdmftGlrloe0DRWZgLX9kOSsQ54K+n3KKat5KjozC8o9KXrtc5qRU50ic9KBStovV1HaOxidkhGiQ=" Oct 12 23:34:46 bcik go-librespot[4141]: time="2026-10-12T23:34:46+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 23:34:46 bcik go-librespot[4141]: time="2026-10-12T23:34:46+02:00" level=debug msg="completed keyexchange" Oct 12 23:34:46 bcik go-librespot[4141]: time="2026-10-12T23:34:46+02:00" level=debug msg="completed challenge" Oct 12 23:34:46 bcik go-librespot[4141]: time="2026-10-12T23:34:46+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 23:34:46 bcik go-librespot[4141]: time="2026-10-12T23:34:46+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 23:34:46 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 23:34:46 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 23:34:47 bcik volumio[3307]: info: Initializing connection to go-librespot Websocket Oct 12 23:34:47 bcik volumio[3307]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 23:34:50 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 452. Oct 12 23:34:50 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 23:34:50 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 23:34:50 bcik go-librespot[4150]: go-librespot daemon starting... Oct 12 23:34:50 bcik go-librespot[4151]: time="2026-10-12T23:34:50+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 23:34:50 bcik go-librespot[4151]: time="2026-10-12T23:34:50+02:00" level=debug msg="app state loaded" Oct 12 23:34:50 bcik go-librespot[4151]: time="2026-10-12T23:34:50+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 23:34:50 bcik go-librespot[4151]: time="2026-10-12T23:34:50+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 12 23:34:50 bcik go-librespot[4151]: time="2026-10-12T23:34:50+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 12 23:34:50 bcik go-librespot[4151]: time="2026-10-12T23:34:50+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 12 23:34:50 bcik go-librespot[4151]: time="2026-10-12T23:34:50+02:00" level=info msg="zeroconf server listening on port 35903" Oct 12 23:34:50 bcik go-librespot[4151]: time="2026-10-12T23:34:50+02:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: invalid status code from clienttoken: 503" Oct 12 23:34:50 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 23:34:50 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 23:34:50 bcik volumio[3307]: info: Initializing connection to go-librespot Websocket Oct 12 23:34:50 bcik volumio[3307]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 23:34:53 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 453. Oct 12 23:34:53 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 23:34:53 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 23:34:53 bcik go-librespot[4160]: go-librespot daemon starting... Oct 12 23:34:53 bcik go-librespot[4161]: time="2026-10-12T23:34:53+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 23:34:53 bcik go-librespot[4161]: time="2026-10-12T23:34:53+02:00" level=debug msg="app state loaded" Oct 12 23:34:53 bcik go-librespot[4161]: time="2026-10-12T23:34:53+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 23:34:53 bcik go-librespot[4161]: time="2026-10-12T23:34:53+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 12 23:34:53 bcik go-librespot[4161]: time="2026-10-12T23:34:53+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 12 23:34:53 bcik go-librespot[4161]: time="2026-10-12T23:34:53+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 12 23:34:53 bcik go-librespot[4161]: time="2026-10-12T23:34:53+02:00" level=info msg="zeroconf server listening on port 45793" Oct 12 23:34:53 bcik volumio[3307]: info: Initializing connection to go-librespot Websocket Oct 12 23:34:53 bcik go-librespot[4161]: time="2026-10-12T23:34:53+02:00" level=debug msg="new websocket client" Oct 12 23:34:53 bcik volumio[3307]: info: Connection to go-librespot Websocket established Oct 12 23:34:56 bcik volumio[3307]: info: Getting Spotify volume Oct 12 23:34:56 bcik volumio[3307]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Oct 12 23:34:56 bcik volumio[3307]: info: CoreCommandRouter::volumioGetState Oct 12 23:34:56 bcik volumio[3307]: info: CorePlayQueue::getTrack 0 Oct 12 23:34:56 bcik volumio[3307]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 Oct 12 23:34:56 bcik volumio[3307]: SPOTIFY: SPOTIFY VOLUME undefined Oct 12 23:34:56 bcik volumio[3307]: SPOTIFY: VOLUMIO VOLUME 41 Oct 12 23:34:56 bcik volumio[3307]: info: Aligning Spotify Volume to Volumio Volume Oct 12 23:34:56 bcik volumio[3307]: info: CoreCommandRouter::volumioGetState Oct 12 23:34:56 bcik volumio[3307]: info: CorePlayQueue::getTrack 0 Oct 12 23:34:56 bcik volumio[3307]: info: Setting Spotify Volume from Volumio: 41 Oct 12 23:34:58 bcik volumio[3307]: SPOTIFY: SETTING SPOTIFY VOLUME 41 Oct 12 23:34:58 bcik volumio[3307]: info: Sending Spotify command with payload to local API: /player/volume Oct 12 23:34:58 bcik go-librespot[4161]: time="2026-10-12T23:34:58+02:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: invalid status code from clienttoken: 504" Oct 12 23:34:58 bcik volumio[3307]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Oct 12 23:34:58 bcik volumio[3307]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 23:34:58 bcik volumio[3307]: Error: socket hang up Oct 12 23:34:58 bcik volumio[3307]: at connResetException (node:internal/errors:720:14) Oct 12 23:34:58 bcik volumio[3307]: at Socket.socketOnEnd (node:_http_client:519:23) Oct 12 23:34:58 bcik volumio[3307]: at Socket.emit (node:events:526:35) Oct 12 23:34:58 bcik volumio[3307]: at endReadableNT (node:internal/streams/readable:1376:12) Oct 12 23:34:58 bcik volumio[3307]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Oct 12 23:34:58 bcik volumio[3307]: code: 'ECONNRESET', Oct 12 23:34:58 bcik volumio[3307]: response: undefined Oct 12 23:34:58 bcik volumio[3307]: } Oct 12 23:34:58 bcik volumio[3307]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 23:34:58 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 23:34:58 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 23:34:58 bcik sudo[4198]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-12 23:33' Oct 12 23:34:58 bcik sudo[4198]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 23:34:58 bcik sudo[4198]: pam_unix(sudo:session): session closed for user root Oct 12 23:34:58 bcik volumio-remote-updater[9031]: [2026-10-12 23:34:58] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Oct 12 23:34:58 bcik volumio-remote-updater[9031]: [2026-10-12 23:34:58] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Oct 12 23:34:58 bcik volumio5-onboarding[32041]: time=2026-10-12T23:34:58.841+02:00 level=ERROR msg="failed reading message" error="websocket: close 1006 (abnormal closure): unexpected EOF" Oct 12 23:34:58 bcik volumio5-onboarding[32041]: time=2026-10-12T23:34:58.841+02:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Oct 12 23:34:58 bcik systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Oct 12 23:34:58 bcik systemd[1]: volumio.service: Failed with result 'exit-code'. Oct 12 23:34:58 bcik systemd[1]: volumio.service: Consumed 6.928s CPU time. Oct 12 23:34:58 bcik systemd[1]: Started dynamicswap.service - dynamicswap service. Oct 12 23:34:58 bcik systemd[1]: dynamicswap.service: Deactivated successfully. Oct 12 23:34:59 bcik systemd[1]: volumio.service: Scheduled restart job, restart counter is at 22793. Oct 12 23:34:59 bcik systemd[1]: Started dynamicswap.service - dynamicswap service. Oct 12 23:34:59 bcik systemd[1]: Stopped volumio.service - Volumio Backend Module. Oct 12 23:34:59 bcik systemd[1]: volumio.service: Consumed 6.928s CPU time. Oct 12 23:34:59 bcik systemd[1]: Started volumio.service - Volumio Backend Module. Oct 12 23:34:59 bcik systemd[1]: dynamicswap.service: Deactivated successfully. Oct 12 23:34:59 bcik volumio[4222]: info: ------------------------------------------- Oct 12 23:34:59 bcik volumio[4222]: info: ----- Volumio3 ---- Oct 12 23:34:59 bcik volumio[4222]: info: ------------------------------------------- Oct 12 23:34:59 bcik volumio[4222]: info: ----- System startup ---- Oct 12 23:34:59 bcik volumio[4222]: info: ------------------------------------------- Oct 12 23:34:59 bcik volumio[4222]: info: MYVOLUMIO Environment detected Oct 12 23:34:59 bcik volumio[4222]: info: Plugin folders cleanup Oct 12 23:34:59 bcik volumio[4222]: info: Scanning into folder /volumio/app/plugins/ Oct 12 23:34:59 bcik volumio[4222]: info: Scanning category audio_interface Oct 12 23:34:59 bcik volumio[4222]: info: Scanning category miscellanea Oct 12 23:34:59 bcik volumio[4222]: info: Scanning category music_service Oct 12 23:34:59 bcik volumio[4222]: info: Scanning category plugins.json Oct 12 23:34:59 bcik volumio[4222]: info: Scanning category system_controller Oct 12 23:34:59 bcik volumio[4222]: info: Scanning category user_interface Oct 12 23:34:59 bcik volumio[4222]: info: Scanning into folder /data/plugins/ Oct 12 23:34:59 bcik volumio[4222]: info: Scanning category music_service Oct 12 23:34:59 bcik volumio[4222]: info: Plugin folders cleanup completed Oct 12 23:34:59 bcik volumio[4222]: info: ------------------------------------------- Oct 12 23:34:59 bcik volumio[4222]: info: ----- Core plugins startup ---- Oct 12 23:34:59 bcik volumio[4222]: info: ------------------------------------------- Oct 12 23:34:59 bcik volumio[4222]: info: Loading plugins from folder /volumio/app/plugins/ Oct 12 23:34:59 bcik volumio[4222]: info: Adding plugin upnp to MyMusic Plugins Oct 12 23:34:59 bcik volumio[4222]: info: Adding plugin airplay_emulation to MyMusic Plugins Oct 12 23:34:59 bcik volumio[4222]: info: Adding plugin upnp_browser to MyMusic Plugins Oct 12 23:34:59 bcik volumio[4222]: info: Loading plugins from folder /data/plugins/ Oct 12 23:34:59 bcik volumio[4222]: info: Loading plugin "system"... Oct 12 23:34:59 bcik volumio[4222]: info: Loading plugin "appearance"... Oct 12 23:34:59 bcik volumio[4222]: info: Loading plugin "network"... Oct 12 23:34:59 bcik volumio[4222]: info: Refreshing Cached IP Addresses Oct 12 23:34:59 bcik volumio[4222]: info: Loading plugin "services"... Oct 12 23:34:59 bcik volumio[4222]: info: Loading plugin "volumio5onboarding"... Oct 12 23:34:59 bcik sudo[4250]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 12 23:34:59 bcik sudo[4252]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 12 23:34:59 bcik sudo[4250]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 23:34:59 bcik sudo[4252]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 23:34:59 bcik sudo[4252]: pam_unix(sudo:session): session closed for user root Oct 12 23:34:59 bcik sudo[4250]: pam_unix(sudo:session): session closed for user root Oct 12 23:34:59 bcik volumio[4222]: info: Loading plugin "alsa_controller"... Oct 12 23:34:59 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 12 23:34:59 bcik volumio[4222]: info: Loading plugin "wizard"... Oct 12 23:34:59 bcik volumio[4222]: info: Loading plugin "networkfs"... Oct 12 23:34:59 bcik volumio[4222]: info: Starting Udev Watcher for removable devices Oct 12 23:34:59 bcik volumio[4222]: info: Ignoring mount for partition: boot Oct 12 23:34:59 bcik volumio[4222]: info: Ignoring mount for partition: volumio Oct 12 23:34:59 bcik volumio[4222]: info: Ignoring mount for partition: volumio_data Oct 12 23:34:59 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 12 23:34:59 bcik volumio[4222]: info: Loading plugin "volumio_command_line_client"... Oct 12 23:34:59 bcik volumio[4222]: info: Loading plugin "upnp"... Oct 12 23:34:59 bcik volumio[4222]: info: [1791840899863] Starting Upmpd Daemon Oct 12 23:34:59 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 12 23:34:59 bcik volumio[4222]: info: Loading plugin "my_music"... Oct 12 23:34:59 bcik volumio[4222]: info: Loading plugin "mpd"... Oct 12 23:34:59 bcik volumio[4222]: info: Loading plugin "upnp_browser"... Oct 12 23:35:00 bcik volumio[4222]: info: Starting UPNP Browser Oct 12 23:35:00 bcik volumio[4222]: info: Loading plugin "alarm-clock"... Oct 12 23:35:00 bcik volumio[4222]: info: Loading plugin "airplay_emulation"... Oct 12 23:35:00 bcik volumio[4222]: info: Starting Shairport Sync Oct 12 23:35:00 bcik volumio[4222]: info: Loading plugin "last_100"... Oct 12 23:35:00 bcik volumio[4222]: info: Loading plugin "webradio"... Oct 12 23:35:00 bcik volumio[4222]: info: Loading plugin "i2s_dacs"... Oct 12 23:35:00 bcik volumio[4222]: info: Loading plugin "volumiodiscovery"... Oct 12 23:35:00 bcik volumio[4222]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 12 23:35:00 bcik volumio[4222]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 12 23:35:00 bcik volumio[4222]: *** WARNING *** For more information see Oct 12 23:35:00 bcik volumio[4222]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 12 23:35:00 bcik volumio[4222]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 12 23:35:00 bcik volumio[4222]: *** WARNING *** For more information see Oct 12 23:35:00 bcik node[4222]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 12 23:35:00 bcik node[4222]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 12 23:35:00 bcik node[4222]: *** WARNING *** For more information see Oct 12 23:35:00 bcik node[4222]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 12 23:35:00 bcik node[4222]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 12 23:35:00 bcik node[4222]: *** WARNING *** For more information see Oct 12 23:35:00 bcik volumio[4222]: info: Applying required configuration parameters for plugin volumiodiscovery Oct 12 23:35:00 bcik volumio[4222]: info: Discovery: Started advertising with name: Bącik Oct 12 23:35:00 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 12 23:35:00 bcik volumio[4222]: info: Loading plugin "spop"... Oct 12 23:35:00 bcik volumio[4222]: info: Loading plugin "outputs"... Oct 12 23:35:00 bcik volumio[4222]: info: Loading plugin "albumart"... Oct 12 23:35:00 bcik volumio[4222]: info: Plugin example_plugin is not enabled Oct 12 23:35:00 bcik volumio[4222]: info: Loading plugin "inputs"... Oct 12 23:35:00 bcik volumio[4222]: info: Loading plugin "updater_comm"... Oct 12 23:35:00 bcik volumio[4222]: info: Plugin mpdemulation is not enabled Oct 12 23:35:00 bcik volumio[4222]: info: Loading plugin "rest_api"... Oct 12 23:35:00 bcik volumio[4222]: info: Loading plugin "websocket"... Oct 12 23:35:00 bcik volumio[4222]: info: Starting Socket.io Server version 1.7.4 Oct 12 23:35:00 bcik volumio[4222]: info: Loading plugin "radio_browser"... Oct 12 23:35:00 bcik volumio[4282]: Forking 3 albumart workers Oct 12 23:35:00 bcik volumio[4222]: info: Loading i18n strings for locale pl Oct 12 23:35:00 bcik volumio[4222]: Updating browse sources language Oct 12 23:35:00 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 23:35:00 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 23:35:00 bcik volumio[4222]: info: CoreCommandRouter::initPlayerControls Oct 12 23:35:00 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 23:35:00 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 23:35:00 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 23:35:00 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 23:35:00 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 23:35:00 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 23:35:00 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 23:35:00 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 23:35:00 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 23:35:00 bcik volumio[4222]: Express server listening on port 3000 Oct 12 23:35:00 bcik volumio[4222]: [Metrics] WebUI: 1s 278.38ms Oct 12 23:35:00 bcik volumio[4222]: info: CoreStateMachine::resetVolumioState Oct 12 23:35:00 bcik volumio[4222]: info: CoreStateMachine::getcurrentVolume Oct 12 23:35:00 bcik volumio[4222]: info: CoreCommandRouter::volumioRetrievevolume Oct 12 23:35:00 bcik volumio[4222]: info: Volumio Network Manager: Network status updated: 1 Oct 12 23:35:00 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 12 23:35:00 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 23:35:00 bcik volumio[4222]: info: Reloading queue from file Oct 12 23:35:00 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 12 23:35:00 bcik volumio[4222]: info: CoreStateMachine::setRepeat false single undefined Oct 12 23:35:00 bcik volumio[4222]: info: CoreStateMachine::pushState Oct 12 23:35:00 bcik volumio[4222]: info: CorePlayQueue::getTrack 0 Oct 12 23:35:00 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 23:35:00 bcik volumio[4222]: info: CoreCommandRouter::volumioPushState Oct 12 23:35:00 bcik volumio[4222]: info: CoreStateMachine::setRandom false Oct 12 23:35:00 bcik volumio[4222]: info: CoreStateMachine::pushState Oct 12 23:35:00 bcik volumio[4222]: info: CorePlayQueue::getTrack 0 Oct 12 23:35:00 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 23:35:00 bcik volumio[4222]: info: CoreCommandRouter::volumioPushState Oct 12 23:35:00 bcik volumio[4222]: info: VolumeController:: Volume=41 Mute =false Oct 12 23:35:00 bcik volumio[4222]: info: CoreStateMachine::pushState Oct 12 23:35:00 bcik volumio[4222]: info: CorePlayQueue::getTrack 0 Oct 12 23:35:00 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 23:35:00 bcik volumio[4222]: info: CoreCommandRouter::volumioPushState Oct 12 23:35:00 bcik volumio[4222]: info: CoreStateMachine::updateTrackBlock Oct 12 23:35:00 bcik volumio[4222]: info: CorePlayQueue::getTrackBlock Oct 12 23:35:00 bcik volumio[4222]: info: CoreCommandRouter::volumioRetrievevolume Oct 12 23:35:00 bcik volumio[4222]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Oct 12 23:35:00 bcik volumio[4222]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04171 Oct 12 23:35:00 bcik volumio[4222]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Oct 12 23:35:00 bcik volumio[4222]: info: Setting Device type: Raspberry PI Oct 12 23:35:00 bcik volumio[4222]: info: Completed loading Core Plugins Oct 12 23:35:00 bcik volumio[4222]: info: Preparing to generate the ALSA configuration file Oct 12 23:35:00 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 12 23:35:00 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 12 23:35:00 bcik volumio[4222]: info: Asound.conf file unchanged, so no further update is needed Oct 12 23:35:00 bcik volumio[4222]: info: Output device has changed, restarting MPD Oct 12 23:35:00 bcik volumio[4222]: info: Output device has changed, restarting Shairport Sync Oct 12 23:35:00 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 23:35:00 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 23:35:00 bcik sudo[4337]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 12 23:35:00 bcik sudo[4337]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 23:35:00 bcik sudo[4341]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 12 23:35:00 bcik sudo[4341]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 23:35:00 bcik sudo[4337]: pam_unix(sudo:session): session closed for user root Oct 12 23:35:00 bcik volumio[4222]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 12 23:35:00 bcik volumio[4222]: info: ___________ START PLUGINS ___________ Oct 12 23:35:00 bcik volumio[4222]: info: ControllerMpd::onStart: Initializing MPD Oct 12 23:35:00 bcik volumio[4222]: info: Creating MPD Configuration file Oct 12 23:35:00 bcik systemd[1]: Stopping mpd.service - Music Player Daemon... Oct 12 23:35:00 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 23:35:00 bcik volumio[4222]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 12 23:35:00 bcik volumio[4222]: info: [1791840900781] CoreMusicLibrary::Adding element Serwery Mediów Oct 12 23:35:00 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 23:35:00 bcik volumio[4222]: info: UPNP Browser: Client initialized successfully Oct 12 23:35:00 bcik sudo[4347]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Oct 12 23:35:00 bcik sudo[4347]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 23:35:00 bcik sudo[4349]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 12 23:35:00 bcik sudo[4349]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 23:35:00 bcik sudo[4349]: pam_unix(sudo:session): session closed for user root Oct 12 23:35:00 bcik systemd[1]: mpd.service: Deactivated successfully. Oct 12 23:35:00 bcik systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 12 23:35:00 bcik sudo[4351]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 12 23:35:00 bcik sudo[4351]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 23:35:00 bcik systemd[1]: mpd.socket: Deactivated successfully. Oct 12 23:35:00 bcik systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 12 23:35:00 bcik systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 12 23:35:00 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 23:35:00 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 23:35:00 bcik volumio[4222]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 12 23:35:00 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 23:35:00 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 23:35:00 bcik volumio[4222]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 12 23:35:00 bcik volumio[4222]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 12 23:35:00 bcik volumio[4222]: info: [1791840900835] CoreMusicLibrary::Adding element Last_100 Oct 12 23:35:00 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 23:35:00 bcik volumio[4222]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 12 23:35:00 bcik volumio[4222]: info: [1791840900835] CoreMusicLibrary::Adding element Webradio Oct 12 23:35:00 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 23:35:00 bcik systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 12 23:35:00 bcik systemd[1]: Starting mpd.service - Music Player Daemon... Oct 12 23:35:00 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 12 23:35:00 bcik volumio[4222]: info: Initializing BBC Radios Oct 12 23:35:00 bcik sudo[4347]: pam_unix(sudo:session): session closed for user root Oct 12 23:35:00 bcik systemd[1]: mpd.service: Deactivated successfully. Oct 12 23:35:00 bcik systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 12 23:35:00 bcik systemd[1]: mpd.socket: Deactivated successfully. Oct 12 23:35:00 bcik systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 12 23:35:00 bcik systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 12 23:35:00 bcik systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 12 23:35:00 bcik systemd[1]: Starting mpd.service - Music Player Daemon... Oct 12 23:35:00 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 12 23:35:00 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 23:35:00 bcik volumio[4222]: info: Creating Spotify config file Oct 12 23:35:00 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 23:35:00 bcik volumio[4293]: Starting albumart workers Oct 12 23:35:00 bcik sudo[4379]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 12 23:35:00 bcik sudo[4379]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 12 23:35:00 bcik sudo[4379]: pam_unix(sudo:session): session closed for user root Oct 12 23:35:00 bcik volumio[4294]: Starting albumart workers Oct 12 23:35:00 bcik volumio[4222]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 12 23:35:00 bcik volumio[4222]: info: [1791840900972] CoreMusicLibrary::Adding element Radio Browser Oct 12 23:35:00 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 23:35:00 bcik volumio[4222]: Cannot find translation for source Radio Browser Oct 12 23:35:00 bcik volumio[4222]: info: Volumio Calling Home Oct 12 23:35:01 bcik volumio[4292]: Starting albumart workers Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 12 23:35:01 bcik volumio[4222]: info: MPD Permissions set Oct 12 23:35:01 bcik volumio[4222]: info: MPD Permissions set Oct 12 23:35:01 bcik volumio[4222]: info: VolumeController:: Volume=41 Mute =false Oct 12 23:35:01 bcik volumio[4222]: info: CoreStateMachine::pushState Oct 12 23:35:01 bcik volumio[4222]: info: CorePlayQueue::getTrack 0 Oct 12 23:35:01 bcik volumio[4222]: info: CoreCommandRouter::volumioPushState Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 12 23:35:01 bcik volumio[4222]: info: Volumio called home Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 23:35:01 bcik volumio[4222]: info: Spotify config file written Oct 12 23:35:01 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 23:35:01 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 23:35:01 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 23:35:01 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 23:35:01 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 23:35:01 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 23:35:01 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 23:35:01 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 23:35:01 bcik sudo[4392]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Oct 12 23:35:01 bcik sudo[4392]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 23:35:01 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 23:35:01 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 23:35:01 bcik volumio[4222]: info: No need to fix Spotify hosts Oct 12 23:35:01 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 23:35:01 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 23:35:01 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 23:35:01 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 23:35:01 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 23:35:01 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 23:35:01 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 23:35:01 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 23:35:01 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 23:35:01 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 23:35:01 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 23:35:01 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 23:35:01 bcik go-librespot[4410]: go-librespot daemon starting... Oct 12 23:35:01 bcik sudo[4392]: pam_unix(sudo:session): session closed for user root Oct 12 23:35:01 bcik go-librespot[4411]: time="2026-10-12T23:35:01+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 23:35:01 bcik go-librespot[4411]: time="2026-10-12T23:35:01+02:00" level=debug msg="app state loaded" Oct 12 23:35:01 bcik go-librespot[4411]: time="2026-10-12T23:35:01+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 23:35:01 bcik volumio[4222]: info: Starting Shairport Sync Oct 12 23:35:01 bcik volumio[4222]: info: Starting Shairport Sync Oct 12 23:35:01 bcik volumio[4222]: info: Starting Shairport Sync Oct 12 23:35:01 bcik sudo[4420]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 12 23:35:01 bcik sudo[4420]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 23:35:01 bcik sudo[4422]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 12 23:35:01 bcik sudo[4422]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 23:35:01 bcik volumio[4222]: info: An error occurred while refreshing Spotify Token Error: Bad Request Oct 12 23:35:01 bcik sudo[4425]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 12 23:35:01 bcik sudo[4425]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 23:35:01 bcik systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 12 23:35:01 bcik systemd[1]: shairport-sync.service: Deactivated successfully. Oct 12 23:35:01 bcik systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 12 23:35:01 bcik systemd[1]: shairport-sync.service: Consumed 1.636s CPU time. Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 23:35:01 bcik volumio[4222]: info: Discovery: adding f1ed5fb6-e21d-47c8-819b-29842600355e Oct 12 23:35:01 bcik volumio[4222]: info: Discovery: Found device Bącik Oct 12 23:35:01 bcik volumio[4222]: info: CoreCommandRouter::volumioGetState Oct 12 23:35:01 bcik volumio[4222]: info: CorePlayQueue::getTrack 0 Oct 12 23:35:01 bcik volumio[4222]: info: CoreCommandRouter::volumioGetState Oct 12 23:35:01 bcik volumio[4222]: info: CorePlayQueue::getTrack 0 Oct 12 23:35:01 bcik systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 12 23:35:01 bcik sudo[4422]: pam_unix(sudo:session): session closed for user root Oct 12 23:35:01 bcik sudo[4420]: pam_unix(sudo:session): session closed for user root Oct 12 23:35:01 bcik volumio[4222]: info: Discovery: this is already registered, f1ed5fb6-e21d-47c8-819b-29842600355e Oct 12 23:35:01 bcik systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 12 23:35:01 bcik go-librespot[4411]: time="2026-10-12T23:35:01+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 12 23:35:01 bcik go-librespot[4411]: time="2026-10-12T23:35:01+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 12 23:35:01 bcik go-librespot[4411]: time="2026-10-12T23:35:01+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 12 23:35:01 bcik systemd[1]: shairport-sync.service: Deactivated successfully. Oct 12 23:35:01 bcik systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 12 23:35:01 bcik volumio[4222]: info: Discovery: Found device Bącik Oct 12 23:35:01 bcik volumio[4222]: info: CoreCommandRouter::volumioGetState Oct 12 23:35:01 bcik volumio[4222]: info: CorePlayQueue::getTrack 0 Oct 12 23:35:01 bcik systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 12 23:35:01 bcik sudo[4425]: pam_unix(sudo:session): session closed for user root Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 23:35:01 bcik go-librespot[4411]: time="2026-10-12T23:35:01+02:00" level=info msg="zeroconf server listening on port 40117" Oct 12 23:35:01 bcik volumio[4222]: info: Shairport-Sync Started Oct 12 23:35:01 bcik volumio[4222]: Error adding Membership: Error: addMembership EINVAL Oct 12 23:35:01 bcik volumio[4222]: info: Shairport-Sync Started Oct 12 23:35:01 bcik volumio[4222]: info: Shairport-Sync Started Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 23:35:01 bcik go-librespot[4411]: time="2026-10-12T23:35:01+02:00" level=debug msg="obtained new client token: AAETGaT9XVycqxZujvIvjNMeApQBIWHPARvht5qeNzHPiyt+i/Qqr6MhlSUc83QjrHtk5uvCmEnjIjPccYoPWn9Zn28RGf+gc7OwvN63M2wCPkQPbV+zrabFW7EbFc3bBTe7qz6qBQRYjCHljNIjISdBtPvKc7YcGXEMXz8IirsgiEu545SiaypZCBF5e+7JsPkAO0FlilmFDsaDxcDB1oc3NQ3jYYYQvhcvTNMUtN/mqxqOUp7nk0w=" Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 23:35:01 bcik go-librespot[4411]: time="2026-10-12T23:35:01+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 23:35:01 bcik go-librespot[4411]: time="2026-10-12T23:35:01+02:00" level=debug msg="completed keyexchange" Oct 12 23:35:01 bcik go-librespot[4411]: time="2026-10-12T23:35:01+02:00" level=debug msg="completed challenge" Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 23:35:01 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 23:35:01 bcik go-librespot[4411]: time="2026-10-12T23:35:01+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 23:35:01 bcik mpd[4381]: 2026-10-12T23:35:01 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 12 23:35:01 bcik systemd[1]: Started mpd.service - Music Player Daemon. Oct 12 23:35:01 bcik sudo[4351]: pam_unix(sudo:session): session closed for user root Oct 12 23:35:01 bcik sudo[4341]: pam_unix(sudo:session): session closed for user root Oct 12 23:35:01 bcik volumio[4222]: info: Completed starting Core Plugins Oct 12 23:35:01 bcik volumio[4222]: info: ------------------------------------------- Oct 12 23:35:01 bcik volumio[4222]: info: ----- MyVolumio plugins startup ---- Oct 12 23:35:01 bcik volumio[4222]: info: ------------------------------------------- Oct 12 23:35:01 bcik volumio[4222]: info: [MyVolumio PluginManager] Fetching plans data.... Oct 12 23:35:01 bcik volumio[4222]: error: MPD error: The expression evaluated to a falsy value: Oct 12 23:35:01 bcik volumio[4222]: assert.ok(self.idling) Oct 12 23:35:01 bcik volumio[4222]: error: The expression evaluated to a falsy value: Oct 12 23:35:01 bcik volumio[4222]: assert.ok(self.idling) Oct 12 23:35:01 bcik volumio[4222]: info: MPD running with PID4381 Oct 12 23:35:01 bcik volumio[4222]: ,establishing connection Oct 12 23:35:01 bcik volumio[4222]: error: updateQueue error: null Oct 12 23:35:01 bcik volumio[4222]: error: updateQueue error: null Oct 12 23:35:01 bcik go-librespot[4411]: time="2026-10-12T23:35:01+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 23:35:01 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 23:35:01 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 23:35:03 bcik volumio-remote-updater[9031]: [2026-10-12 23:35:03] [connect] Successful connection Oct 12 23:35:03 bcik volumio-remote-updater[9031]: [2026-10-12 23:35:03] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1791840903 101 Oct 12 23:35:03 bcik volumio[4222]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 3 Oct 12 23:35:04 bcik volumio[4222]: info: go-librespot daemon successfully initialized Oct 12 23:35:04 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 454. Oct 12 23:35:04 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 23:35:04 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 23:35:04 bcik go-librespot[4460]: go-librespot daemon starting... Oct 12 23:35:04 bcik go-librespot[4461]: time="2026-10-12T23:35:04+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 23:35:04 bcik go-librespot[4461]: time="2026-10-12T23:35:04+02:00" level=debug msg="app state loaded" Oct 12 23:35:04 bcik go-librespot[4461]: time="2026-10-12T23:35:04+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 23:35:04 bcik go-librespot[4461]: time="2026-10-12T23:35: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-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 12 23:35:04 bcik go-librespot[4461]: time="2026-10-12T23:35:04+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 12 23:35:04 bcik go-librespot[4461]: time="2026-10-12T23:35:04+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 12 23:35:04 bcik go-librespot[4461]: time="2026-10-12T23:35:04+02:00" level=info msg="zeroconf server listening on port 36725" Oct 12 23:35:04 bcik go-librespot[4461]: time="2026-10-12T23:35:04+02:00" level=debug msg="obtained new client token: AAFEcL9GskVcioHgMxZf32xAee10IAi8yeouAGa9hc+ey3G20LX+EJNjteXGH7pt49Tk8wo/sMhwYXIBRa9aK5R3MH37AjuTBkYUl6sWqcRiiyz0Ltkyrx4Usx0CaYcEQelmLJlxJ51PH4Pvv6Pod11sMXe4GrsHRRT8gCVQRTHsePvwzu46dIhfvNNhk6tTZ+sr0A6B2UsFu8cKI8h8mJuRffUTWl3r6dhyjXNcbyP2dcOiMgD7+Xg=" Oct 12 23:35:04 bcik go-librespot[4461]: time="2026-10-12T23:35:04+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 23:35:04 bcik go-librespot[4461]: time="2026-10-12T23:35:04+02:00" level=debug msg="completed keyexchange" Oct 12 23:35:04 bcik go-librespot[4461]: time="2026-10-12T23:35:04+02:00" level=debug msg="completed challenge" Oct 12 23:35:04 bcik go-librespot[4461]: time="2026-10-12T23:35:04+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 23:35:04 bcik go-librespot[4461]: time="2026-10-12T23:35:04+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 23:35:04 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 23:35:04 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 23:35:06 bcik volumio[4222]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Oct 12 23:35:07 bcik volumio[4222]: info: Initializing connection to go-librespot Websocket Oct 12 23:35:07 bcik volumio[4222]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 23:35:08 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 455. Oct 12 23:35:08 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 23:35:08 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 23:35:08 bcik go-librespot[4472]: go-librespot daemon starting... Oct 12 23:35:08 bcik go-librespot[4473]: time="2026-10-12T23:35:08+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 23:35:08 bcik go-librespot[4473]: time="2026-10-12T23:35:08+02:00" level=debug msg="app state loaded" Oct 12 23:35:08 bcik go-librespot[4473]: time="2026-10-12T23:35:08+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 23:35:08 bcik go-librespot[4473]: time="2026-10-12T23:35:08+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Oct 12 23:35:08 bcik go-librespot[4473]: time="2026-10-12T23:35:08+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Oct 12 23:35:08 bcik go-librespot[4473]: time="2026-10-12T23:35:08+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Oct 12 23:35:08 bcik go-librespot[4473]: time="2026-10-12T23:35:08+02:00" level=info msg="zeroconf server listening on port 35269" Oct 12 23:35:08 bcik go-librespot[4473]: time="2026-10-12T23:35:08+02:00" level=debug msg="obtained new client token: AAEGtTs9kH1j5HnZkh16M0XJKRQSM7HpdtFG0kpUSjtPTycFcRLKYQ4tadGSlACgLyl2OyTkpwaRdWpsWs0lkRfSIWWXNLv3RGc/uVeKfce9NNR1dncCx4sn8nRL/ii+tCqotQ/m2k3F+jibrwwMdfJUa0qvSg+RAXO6U0szKnrcnSmpXADPBCsD5Jk3O3j+DhigQ9weDEoRoh+vvZppGl/qqfw14M6GgxOhGfBgLnSAtG9722yQ" Oct 12 23:35:08 bcik go-librespot[4473]: time="2026-10-12T23:35:08+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 23:35:08 bcik go-librespot[4473]: time="2026-10-12T23:35:08+02:00" level=debug msg="completed keyexchange" Oct 12 23:35:08 bcik go-librespot[4473]: time="2026-10-12T23:35:08+02:00" level=debug msg="completed challenge" Oct 12 23:35:08 bcik go-librespot[4473]: time="2026-10-12T23:35:08+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 23:35:08 bcik go-librespot[4473]: time="2026-10-12T23:35:08+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 23:35:08 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 23:35:08 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 23:35:09 bcik volumio[4222]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Oct 12 23:35:09 bcik volumio[4222]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Oct 12 23:35:09 bcik volumio[4222]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Oct 12 23:35:09 bcik volumio[4222]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Oct 12 23:35:09 bcik volumio[4222]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Oct 12 23:35:09 bcik volumio[4222]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Oct 12 23:35:09 bcik volumio[4222]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Oct 12 23:35:09 bcik volumio[4222]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Oct 12 23:35:09 bcik volumio[4222]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Oct 12 23:35:09 bcik volumio[4222]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Oct 12 23:35:09 bcik volumio[4222]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Oct 12 23:35:09 bcik volumio[4222]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Oct 12 23:35:09 bcik volumio[4222]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Oct 12 23:35:09 bcik volumio[4222]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Oct 12 23:35:09 bcik volumio[4222]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Oct 12 23:35:09 bcik volumio[4222]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Oct 12 23:35:09 bcik volumio[4222]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Oct 12 23:35:09 bcik volumio[4222]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Oct 12 23:35:09 bcik volumio[4222]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Oct 12 23:35:09 bcik volumio[4222]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Oct 12 23:35:09 bcik volumio[4222]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Oct 12 23:35:09 bcik volumio[4222]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Oct 12 23:35:09 bcik volumio[4222]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Oct 12 23:35:09 bcik volumio[4222]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Oct 12 23:35:09 bcik volumio[4222]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Oct 12 23:35:09 bcik volumio[4222]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Oct 12 23:35:09 bcik volumio[4222]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Oct 12 23:35:09 bcik volumio[4222]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Oct 12 23:35:09 bcik volumio[4222]: info: Adding plugin bluetooth to MyMusic Plugins Oct 12 23:35:09 bcik volumio[4222]: info: Adding plugin multiroom to MyMusic Plugins Oct 12 23:35:09 bcik volumio[4222]: info: Adding plugin metavolumio to MyMusic Plugins Oct 12 23:35:09 bcik volumio[4222]: info: Adding plugin cd_controller to MyMusic Plugins Oct 12 23:35:09 bcik volumio[4222]: info: Adding plugin qobuzconnect to MyMusic Plugins Oct 12 23:35:09 bcik volumio[4222]: info: Adding plugin smart_inputs to MyMusic Plugins Oct 12 23:35:09 bcik volumio[4222]: info: Adding plugin tidalconnect to MyMusic Plugins Oct 12 23:35:09 bcik volumio[4222]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Oct 12 23:35:10 bcik volumio[4222]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Oct 12 23:35:10 bcik volumio[4222]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Oct 12 23:35:10 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 23:35:10 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 23:35:10 bcik volumio[4222]: info: Starting MyVolumio Remote Streaming Endpoints Oct 12 23:35:10 bcik volumio[4222]: info: MyVolumio login type: Token Oct 12 23:35:10 bcik volumio[4222]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Oct 12 23:35:10 bcik volumio[4222]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Oct 12 23:35:10 bcik volumio[4222]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Oct 12 23:35:10 bcik volumio[4222]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Oct 12 23:35:10 bcik volumio[4222]: info: Streaming services startup Oct 12 23:35:10 bcik volumio[4222]: info: Starting Streaming Daemon Oct 12 23:35:10 bcik sudo[4497]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 12 23:35:10 bcik sudo[4497]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 23:35:10 bcik volumio[4222]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Oct 12 23:35:10 bcik sudo[4497]: pam_unix(sudo:session): session closed for user root Oct 12 23:35:10 bcik sudo[4504]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 12 23:35:10 bcik volumio[4222]: error: Cannot start Volumio Streaming Daemon Oct 12 23:35:10 bcik volumio[4222]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 12 23:35:10 bcik volumio[4222]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 12 23:35:10 bcik sudo[4504]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 23:35:10 bcik sudo[4506]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 12 23:35:10 bcik sudo[4506]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 23:35:10 bcik sudo[4504]: pam_unix(sudo:session): session closed for user root Oct 12 23:35:10 bcik sudo[4506]: pam_unix(sudo:session): session closed for user root Oct 12 23:35:10 bcik sudo[4510]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Oct 12 23:35:10 bcik sudo[4510]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 23:35:10 bcik sudo[4510]: pam_unix(sudo:session): session closed for user root Oct 12 23:35:10 bcik volumio[4222]: info: Upmpdcli Daemon Started Oct 12 23:35:10 bcik volumio[4222]: info: Initializing connection to go-librespot Websocket Oct 12 23:35:10 bcik volumio[4222]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 23:35:10 bcik volumio[4222]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Oct 12 23:35:11 bcik volumio[4222]: info: MyVolumio token set successfully Oct 12 23:35:11 bcik volumio[4222]: info: MYVOLUMIO: Adding device Oct 12 23:35:11 bcik volumio[4222]: info: MYVOLUMIO: Evaluating Server Oct 12 23:35:11 bcik volumio[4222]: info: MyVolumio status changed Oct 12 23:35:11 bcik volumio[4222]: info: Streaming services startup Oct 12 23:35:11 bcik volumio[4222]: info: Starting Streaming Daemon Oct 12 23:35:11 bcik volumio[4222]: info: Removing browser output: myVolumio user plan is not superstar Oct 12 23:35:11 bcik volumio[4222]: info: Removing audio output: Oct 12 23:35:11 bcik volumio[4222]: info: Stoppping Tunnel 1 Oct 12 23:35:11 bcik sudo[4533]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 12 23:35:11 bcik sudo[4533]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 23:35:11 bcik sudo[4535]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Oct 12 23:35:11 bcik sudo[4535]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 23:35:11 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 456. Oct 12 23:35:11 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 23:35:11 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 23:35:11 bcik go-librespot[4538]: go-librespot daemon starting... Oct 12 23:35:11 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 23:35:11 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 23:35:11 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 23:35:11 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 23:35:11 bcik sudo[4533]: pam_unix(sudo:session): session closed for user root Oct 12 23:35:11 bcik go-librespot[4539]: time="2026-10-12T23:35:11+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 23:35:11 bcik go-librespot[4539]: time="2026-10-12T23:35:11+02:00" level=debug msg="app state loaded" Oct 12 23:35:11 bcik volumio[4222]: error: Cannot start Volumio Streaming Daemon Oct 12 23:35:11 bcik volumio[4222]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 12 23:35:11 bcik volumio[4222]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 12 23:35:11 bcik go-librespot[4539]: time="2026-10-12T23:35:11+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 23:35:11 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 23:35:11 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 23:35:11 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 23:35:11 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 23:35:11 bcik sudo[4535]: pam_unix(sudo:session): session closed for user root Oct 12 23:35:11 bcik volumio[4222]: info: Remote SSH Stopped Oct 12 23:35:11 bcik go-librespot[4539]: time="2026-10-12T23:35: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-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 12 23:35:11 bcik go-librespot[4539]: time="2026-10-12T23:35:11+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 12 23:35:11 bcik go-librespot[4539]: time="2026-10-12T23:35:11+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 12 23:35:11 bcik go-librespot[4539]: time="2026-10-12T23:35:11+02:00" level=info msg="zeroconf server listening on port 45701" Oct 12 23:35:11 bcik go-librespot[4539]: time="2026-10-12T23:35:11+02:00" level=debug msg="obtained new client token: AAHB7KZqVFXkOlrlLOZabW8QIkC/5nUaXInXN9OIGqSuDbVLxuMjiEIVbAMpmsZxW9Ugy4ELb9IezTWdZNksN4atyDyQe4JM6bE17eWSLNsP02/yTM5fVxpTF3Fq5m2ajhzL5Ymf0iNkKV2xaG7nNQ/Ere5ppNvombSZyjKak6IDa56iHZj6VtEkIWFzjOFACsnH5rA4XFBD+qfg6b+KNBWEGaRzmO0KnCsuCsTxU+4v5qTrYSvGQ20=" Oct 12 23:35:11 bcik go-librespot[4539]: time="2026-10-12T23:35:11+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 23:35:11 bcik go-librespot[4539]: time="2026-10-12T23:35:11+02:00" level=debug msg="completed keyexchange" Oct 12 23:35:11 bcik go-librespot[4539]: time="2026-10-12T23:35:11+02:00" level=debug msg="completed challenge" Oct 12 23:35:11 bcik go-librespot[4539]: time="2026-10-12T23:35:11+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 23:35:11 bcik volumio[4222]: info: Setting Geolocation for MyVolumio to eu6 Oct 12 23:35:11 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 23:35:11 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 23:35:11 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 23:35:11 bcik go-librespot[4539]: time="2026-10-12T23:35:11+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 23:35:11 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 23:35:11 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 23:35:12 bcik volumio[4222]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Oct 12 23:35:12 bcik volumio[4222]: info: Updating MyVolumio device info Oct 12 23:35:12 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 23:35:12 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 23:35:12 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 23:35:13 bcik volumio[4222]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Oct 12 23:35:13 bcik volumio[4222]: info: Initializing connection to go-librespot Websocket Oct 12 23:35:13 bcik volumio[4222]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 23:35:15 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 457. Oct 12 23:35:15 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 23:35:15 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 23:35:15 bcik go-librespot[4548]: go-librespot daemon starting... Oct 12 23:35:15 bcik go-librespot[4549]: time="2026-10-12T23:35:15+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 23:35:15 bcik go-librespot[4549]: time="2026-10-12T23:35:15+02:00" level=debug msg="app state loaded" Oct 12 23:35:15 bcik go-librespot[4549]: time="2026-10-12T23:35:15+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 23:35:15 bcik go-librespot[4549]: time="2026-10-12T23:35:15+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 12 23:35:15 bcik go-librespot[4549]: time="2026-10-12T23:35:15+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 12 23:35:15 bcik go-librespot[4549]: time="2026-10-12T23:35:15+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 12 23:35:15 bcik go-librespot[4549]: time="2026-10-12T23:35:15+02:00" level=info msg="zeroconf server listening on port 41439" Oct 12 23:35:15 bcik go-librespot[4549]: time="2026-10-12T23:35:15+02:00" level=debug msg="obtained new client token: AAGcT18e4xYFvU3+VwvDqD3fN6vPQc+vQ+hyNaTXjHukEyyC5anEIc2SQoshgPmRvXRwP9nDEuUnuxDUQj4d61zgYerP/fXL2eoEjfoP94zkKSO57Ot+Ih+3xsqyF5mRvDqE9BqGn6S4DpWn4FwMeYc+8ITBkKUG7ZcrRLHm6s92aZpHxFu2y2/N3M2WGbQqc5EA0w2byhhAEmUJjsFKGirVt6jOIJqaj2nrf4GupxpZDrzkjBPk" Oct 12 23:35:15 bcik go-librespot[4549]: time="2026-10-12T23:35:15+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 23:35:15 bcik go-librespot[4549]: time="2026-10-12T23:35:15+02:00" level=debug msg="completed keyexchange" Oct 12 23:35:15 bcik go-librespot[4549]: time="2026-10-12T23:35:15+02:00" level=debug msg="completed challenge" Oct 12 23:35:15 bcik go-librespot[4549]: time="2026-10-12T23:35:15+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 23:35:15 bcik go-librespot[4549]: time="2026-10-12T23:35:15+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 23:35:15 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 23:35:15 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 23:35:16 bcik volumio[4222]: info: Initializing connection to go-librespot Websocket Oct 12 23:35:16 bcik volumio[4222]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 23:35:16 bcik volumio[4222]: info: MYVOLUMIO: Adding device Oct 12 23:35:16 bcik volumio[4222]: info: MYVOLUMIO: Evaluating Server Oct 12 23:35:16 bcik volumio[4222]: info: Setting Geolocation for MyVolumio to eu6 Oct 12 23:35:16 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 23:35:16 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 23:35:16 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 23:35:17 bcik volumio[4222]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Oct 12 23:35:17 bcik volumio[4222]: info: Updating MyVolumio device info Oct 12 23:35:17 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 23:35:17 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 23:35:17 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 23:35:18 bcik volumio[4222]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Oct 12 23:35:18 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 458. Oct 12 23:35:18 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 23:35:18 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 23:35:18 bcik go-librespot[4576]: go-librespot daemon starting... Oct 12 23:35:18 bcik go-librespot[4577]: time="2026-10-12T23:35:18+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 23:35:18 bcik go-librespot[4577]: time="2026-10-12T23:35:18+02:00" level=debug msg="app state loaded" Oct 12 23:35:18 bcik go-librespot[4577]: time="2026-10-12T23:35:18+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 23:35:18 bcik go-librespot[4577]: time="2026-10-12T23:35:18+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 12 23:35:18 bcik go-librespot[4577]: time="2026-10-12T23:35:18+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 12 23:35:18 bcik go-librespot[4577]: time="2026-10-12T23:35:18+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 12 23:35:18 bcik go-librespot[4577]: time="2026-10-12T23:35:18+02:00" level=info msg="zeroconf server listening on port 37817" Oct 12 23:35:18 bcik go-librespot[4577]: time="2026-10-12T23:35:18+02:00" level=debug msg="obtained new client token: AAHTIviSPahkJqxPj8hkBxrAsZDCyNu3pvLkf9x+FD/TUnxb9+FyLyoU6Wr+y/PsMYOLZCnY345wJpdIKK9HgftPueNKwiS0Ye3qXFKsi1t4ramnIXSo+UTZhwg44jxsnewBwJegAiNIo8ctCdEZh6Ck1RtGkGep9ZYTqtN4Fk/JAFtcEPP/N+CWpVdoacvp44nbKtoguTQTmUXzsLOY4UaWQietvCdojj4NGwnNCYxazF9QuGjJLlw=" Oct 12 23:35:18 bcik go-librespot[4577]: time="2026-10-12T23:35:18+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 23:35:18 bcik go-librespot[4577]: time="2026-10-12T23:35:18+02:00" level=debug msg="completed keyexchange" Oct 12 23:35:18 bcik go-librespot[4577]: time="2026-10-12T23:35:18+02:00" level=debug msg="completed challenge" Oct 12 23:35:18 bcik go-librespot[4577]: time="2026-10-12T23:35:18+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 23:35:18 bcik go-librespot[4577]: time="2026-10-12T23:35:18+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 23:35:18 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 23:35:18 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 23:35:19 bcik volumio[4222]: info: Initializing connection to go-librespot Websocket Oct 12 23:35:19 bcik volumio[4222]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 23:35:22 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 459. Oct 12 23:35:22 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 23:35:22 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 23:35:22 bcik go-librespot[4602]: go-librespot daemon starting... Oct 12 23:35:22 bcik go-librespot[4603]: time="2026-10-12T23:35:22+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 23:35:22 bcik go-librespot[4603]: time="2026-10-12T23:35:22+02:00" level=debug msg="app state loaded" Oct 12 23:35:22 bcik go-librespot[4603]: time="2026-10-12T23:35:22+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 23:35:22 bcik go-librespot[4603]: time="2026-10-12T23:35:22+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 12 23:35:22 bcik go-librespot[4603]: time="2026-10-12T23:35:22+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 12 23:35:22 bcik go-librespot[4603]: time="2026-10-12T23:35:22+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 12 23:35:22 bcik go-librespot[4603]: time="2026-10-12T23:35:22+02:00" level=info msg="zeroconf server listening on port 41615" Oct 12 23:35:22 bcik go-librespot[4603]: time="2026-10-12T23:35:22+02:00" level=debug msg="obtained new client token: AAHajQCjpiwBcgYG9SHbItzgRqnN0quvCDuKc+RiJwW2JHoG9csWEB2YNNVoeP6aC9crt9nmhAL6HelDO40XFf4zYbMuWFpbgc9TVp7pNZWC+si8ay+dErP0G0mYW3szL3nMr4dSiCU/JQdqYYjdHNm6MwHRhRJ68SyrRpegoEXETL2DcQRcg2ylgq4XcbefgUa8bN6iDtMUREfCiObMs9l+Nr2a4Y24VN2ic0ZA9N5PFEut+jk9" Oct 12 23:35:22 bcik go-librespot[4603]: time="2026-10-12T23:35:22+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 23:35:22 bcik volumio[4222]: info: Initializing connection to go-librespot Websocket Oct 12 23:35:22 bcik go-librespot[4603]: time="2026-10-12T23:35:22+02:00" level=debug msg="completed keyexchange" Oct 12 23:35:22 bcik go-librespot[4603]: time="2026-10-12T23:35:22+02:00" level=debug msg="completed challenge" Oct 12 23:35:22 bcik go-librespot[4603]: time="2026-10-12T23:35:22+02:00" level=debug msg="new websocket client" Oct 12 23:35:22 bcik volumio[4222]: info: Connection to go-librespot Websocket established Oct 12 23:35:22 bcik go-librespot[4603]: time="2026-10-12T23:35:22+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 23:35:22 bcik go-librespot[4603]: time="2026-10-12T23:35:22+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 23:35:22 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 23:35:22 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 23:35:22 bcik volumio[4222]: info: Connection to go-librespot Websocket closed Oct 12 23:35:25 bcik volumio[4222]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 12 23:35:25 bcik volumio[4222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Oct 12 23:35:25 bcik volumio[4222]: info: CoreCommandRouter::volumioGetState Oct 12 23:35:25 bcik volumio[4222]: info: CorePlayQueue::getTrack 0 Oct 12 23:35:25 bcik volumio[4222]: info: Getting Spotify volume Oct 12 23:35:25 bcik volumio[4222]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 23:35:25 bcik volumio[4222]: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 23:35:25 bcik volumio[4222]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Oct 12 23:35:25 bcik volumio[4222]: errno: -111, Oct 12 23:35:25 bcik volumio[4222]: code: 'ECONNREFUSED', Oct 12 23:35:25 bcik volumio[4222]: syscall: 'connect', Oct 12 23:35:25 bcik volumio[4222]: address: '127.0.0.1', Oct 12 23:35:25 bcik volumio[4222]: port: 9879, Oct 12 23:35:25 bcik volumio[4222]: response: undefined Oct 12 23:35:25 bcik volumio[4222]: } Oct 12 23:35:25 bcik volumio[4222]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 23:35:25 bcik sudo[4626]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-12 23:34' Oct 12 23:35:25 bcik sudo[4626]: 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"