Oct 16 17:22:00 bcik volumio[14009]: info: Initializing connection to go-librespot Websocket Oct 16 17:22:00 bcik volumio[14009]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:22:00 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 77. Oct 16 17:22:00 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:22:00 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:22:00 bcik go-librespot[14709]: go-librespot daemon starting... Oct 16 17:22:00 bcik go-librespot[14710]: time="2026-10-16T17:22:00+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:22:00 bcik go-librespot[14710]: time="2026-10-16T17:22:00+02:00" level=debug msg="app state loaded" Oct 16 17:22:00 bcik go-librespot[14710]: time="2026-10-16T17:22:00+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:22:00 bcik go-librespot[14710]: time="2026-10-16T17:22:00+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 16 17:22:00 bcik go-librespot[14710]: time="2026-10-16T17:22:00+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 16 17:22:00 bcik go-librespot[14710]: time="2026-10-16T17:22:00+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 16 17:22:00 bcik go-librespot[14710]: time="2026-10-16T17:22:00+02:00" level=info msg="zeroconf server listening on port 44345" Oct 16 17:22:00 bcik go-librespot[14710]: time="2026-10-16T17:22:00+02:00" level=debug msg="obtained new client token: AAFq0P8QG3mufXn0oCxw0LOO66VEgtfEymThEHYcNVudyh+WVJokMbooVETowfgraYSV0fPgIZRlRXFGm/3S4OhB8m+9n759jc8w7Un4NnLYawIE3ZONPbtCSgws7R45vEOcQSS69oGpwqkaSwxsPlItLwGbxEWclvERfcdA+eq1EFVGtRYg9upnOSVRW0FWfRqWUnSQ6D4bV5UbYNn0T0iwJhGk39NJicu/yhOsBFmIPv+gdQ/32P8=" Oct 16 17:22:00 bcik go-librespot[14710]: time="2026-10-16T17:22:00+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:22:00 bcik go-librespot[14710]: time="2026-10-16T17:22:00+02:00" level=debug msg="completed keyexchange" Oct 16 17:22:00 bcik go-librespot[14710]: time="2026-10-16T17:22:00+02:00" level=debug msg="completed challenge" Oct 16 17:22:00 bcik go-librespot[14710]: time="2026-10-16T17:22:00+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:22:00 bcik go-librespot[14710]: time="2026-10-16T17:22:00+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 16 17:22:00 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:22:00 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:22:03 bcik volumio[14009]: info: Initializing connection to go-librespot Websocket Oct 16 17:22:03 bcik volumio[14009]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:22:03 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 78. Oct 16 17:22:03 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:22:03 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:22:03 bcik go-librespot[14719]: go-librespot daemon starting... Oct 16 17:22:03 bcik go-librespot[14720]: time="2026-10-16T17:22:03+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:22:03 bcik go-librespot[14720]: time="2026-10-16T17:22:03+02:00" level=debug msg="app state loaded" Oct 16 17:22:03 bcik go-librespot[14720]: time="2026-10-16T17:22:03+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:22:03 bcik go-librespot[14720]: time="2026-10-16T17:22:03+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 16 17:22:03 bcik go-librespot[14720]: time="2026-10-16T17:22:03+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 16 17:22:03 bcik go-librespot[14720]: time="2026-10-16T17:22:03+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 16 17:22:03 bcik go-librespot[14720]: time="2026-10-16T17:22:03+02:00" level=info msg="zeroconf server listening on port 39183" Oct 16 17:22:03 bcik go-librespot[14720]: time="2026-10-16T17:22:03+02:00" level=debug msg="obtained new client token: AAE9Fm7+WCn516fx8B2rS01GS6FfrvyFTFHyJFp+ShJhPPjxcm7cOupwzBnbslaXvxPZE4Sv/4j5w4pwtf+GvEM6gtSIn4D4PlwYVu482JVnKoB3gdab0DIdCRyH3xhHmG7NT9JlC6gs8eF67tIVV0IYaKgmF7MKlWpr/oYqoeHeArM7sRgnI61nb6Xy5QYkRlBoL/nr6XxksKmgO6sHqyM6Os2fQtbBf7e/fvl0y6vSKFX4CkVyiGE=" Oct 16 17:22:04 bcik go-librespot[14720]: time="2026-10-16T17:22:04+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:22:04 bcik go-librespot[14720]: time="2026-10-16T17:22:04+02:00" level=debug msg="completed keyexchange" Oct 16 17:22:04 bcik go-librespot[14720]: time="2026-10-16T17:22:04+02:00" level=debug msg="completed challenge" Oct 16 17:22:04 bcik go-librespot[14720]: time="2026-10-16T17:22:04+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:22:04 bcik go-librespot[14720]: time="2026-10-16T17:22: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 16 17:22:04 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:22:04 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:22:06 bcik volumio[14009]: info: Initializing connection to go-librespot Websocket Oct 16 17:22:06 bcik volumio[14009]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:22:07 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 79. Oct 16 17:22:07 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:22:07 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:22:07 bcik go-librespot[14743]: go-librespot daemon starting... Oct 16 17:22:07 bcik go-librespot[14744]: time="2026-10-16T17:22:07+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:22:07 bcik go-librespot[14744]: time="2026-10-16T17:22:07+02:00" level=debug msg="app state loaded" Oct 16 17:22:07 bcik go-librespot[14744]: time="2026-10-16T17:22:07+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:22:07 bcik go-librespot[14744]: time="2026-10-16T17:22:07+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 16 17:22:07 bcik go-librespot[14744]: time="2026-10-16T17:22:07+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 16 17:22:07 bcik go-librespot[14744]: time="2026-10-16T17:22:07+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 16 17:22:07 bcik go-librespot[14744]: time="2026-10-16T17:22:07+02:00" level=info msg="zeroconf server listening on port 36203" Oct 16 17:22:07 bcik go-librespot[14744]: time="2026-10-16T17:22:07+02:00" level=debug msg="obtained new client token: AAGzG3jXSjyYxe2SpqfKPZlZPUifJfqmGluyymP/6SBo6F1YhYA8gPUCdH532UJVcBS6VFCVkO6y5CwXO72j02FgpbMO6IosNXdJxz7oNUohwJytfENvg6AGwo8qjaqQmUSZJPO/n9+dWlFujRflbhnaaPu5b8zj9i2NwPf+ozeSSxc72lzPQz7qhytSqX5JZrndVQknOveIYpNod4N+MTLXkYmNJdwJ6+CPv15uSue2QBdJh2+Fklc=" Oct 16 17:22:07 bcik go-librespot[14744]: time="2026-10-16T17:22:07+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:22:07 bcik go-librespot[14744]: time="2026-10-16T17:22:07+02:00" level=debug msg="completed keyexchange" Oct 16 17:22:07 bcik go-librespot[14744]: time="2026-10-16T17:22:07+02:00" level=debug msg="completed challenge" Oct 16 17:22:07 bcik go-librespot[14744]: time="2026-10-16T17:22:07+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:22:07 bcik go-librespot[14744]: time="2026-10-16T17:22:07+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 16 17:22:07 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:22:07 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:22:09 bcik volumio[14009]: info: Initializing connection to go-librespot Websocket Oct 16 17:22:09 bcik volumio[14009]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:22:10 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 80. Oct 16 17:22:10 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:22:10 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:22:10 bcik go-librespot[14754]: go-librespot daemon starting... Oct 16 17:22:10 bcik go-librespot[14755]: time="2026-10-16T17:22:10+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:22:10 bcik go-librespot[14755]: time="2026-10-16T17:22:10+02:00" level=debug msg="app state loaded" Oct 16 17:22:10 bcik go-librespot[14755]: time="2026-10-16T17:22:10+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:22:10 bcik go-librespot[14755]: time="2026-10-16T17:22:10+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 16 17:22:10 bcik go-librespot[14755]: time="2026-10-16T17:22:10+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 16 17:22:10 bcik go-librespot[14755]: time="2026-10-16T17:22:10+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 16 17:22:10 bcik go-librespot[14755]: time="2026-10-16T17:22:10+02:00" level=info msg="zeroconf server listening on port 33075" Oct 16 17:22:10 bcik go-librespot[14755]: time="2026-10-16T17:22:10+02:00" level=debug msg="obtained new client token: AAFN7erR58YelvevkRuJKDbI+xuuOuQ0sZNmDguLYHCot1OY97zxfm0bmQSK/tPkR/CTYLnQWNwh3gX/23gBPCQfyTRfSQHND00tgzSBEtbQRR+zHV8Rwc+FAGn2gI1TgVl/rsBEv4MLaSfXdouECSVc/vwaOD99zGSd9VHaDFzKG1NSZAuGYHSNUYpPsKl+kBp7aMLAZuHiLvcEeO89xMXp5dweyMbiE1e9qMPGLxMet1OAK/oNIik=" Oct 16 17:22:11 bcik go-librespot[14755]: time="2026-10-16T17:22:11+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:22:11 bcik go-librespot[14755]: time="2026-10-16T17:22:11+02:00" level=debug msg="completed keyexchange" Oct 16 17:22:11 bcik go-librespot[14755]: time="2026-10-16T17:22:11+02:00" level=debug msg="completed challenge" Oct 16 17:22:11 bcik go-librespot[14755]: time="2026-10-16T17:22:11+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:22:11 bcik go-librespot[14755]: time="2026-10-16T17:22: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 16 17:22:11 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:22:11 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:22:12 bcik volumio[14009]: info: Initializing connection to go-librespot Websocket Oct 16 17:22:12 bcik volumio[14009]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:22:14 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 81. Oct 16 17:22:14 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:22:14 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:22:14 bcik go-librespot[14765]: go-librespot daemon starting... Oct 16 17:22:14 bcik go-librespot[14766]: time="2026-10-16T17:22:14+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:22:14 bcik go-librespot[14766]: time="2026-10-16T17:22:14+02:00" level=debug msg="app state loaded" Oct 16 17:22:14 bcik go-librespot[14766]: time="2026-10-16T17:22:14+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:22:14 bcik go-librespot[14766]: time="2026-10-16T17:22:14+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 16 17:22:14 bcik go-librespot[14766]: time="2026-10-16T17:22:14+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 16 17:22:14 bcik go-librespot[14766]: time="2026-10-16T17:22:14+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 16 17:22:14 bcik go-librespot[14766]: time="2026-10-16T17:22:14+02:00" level=info msg="zeroconf server listening on port 37703" Oct 16 17:22:14 bcik go-librespot[14766]: time="2026-10-16T17:22:14+02:00" level=debug msg="obtained new client token: AAE3shuDpdXif+ueW3ky/IKUh5GrkPGbNUT78/+hMKENeDIrxdXe8QRjGaVZLRo5tr70CksIuQP+rxMzRJVZMD3S3B3TOm+1ZrgkvmbyTHZAcEf4WEE0PDwPBWLSQuK+GJKyxSehpV0IER+4fQucdNNIveAXIMBLIsNALgU8ORMIPFtlwcTFpUfxRrenu5dL7tzkwRhOZIRMpTEqr2ZWl5eJFMx+8MMUfRnVG2c4wjatoIqvtwGhOf0=" Oct 16 17:22:14 bcik go-librespot[14766]: time="2026-10-16T17:22:14+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:22:14 bcik go-librespot[14766]: time="2026-10-16T17:22:14+02:00" level=debug msg="completed keyexchange" Oct 16 17:22:14 bcik go-librespot[14766]: time="2026-10-16T17:22:14+02:00" level=debug msg="completed challenge" Oct 16 17:22:14 bcik go-librespot[14766]: time="2026-10-16T17:22:14+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:22:14 bcik go-librespot[14766]: time="2026-10-16T17:22:14+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 16 17:22:14 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:22:14 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:22:15 bcik volumio[14009]: info: Initializing connection to go-librespot Websocket Oct 16 17:22:15 bcik volumio[14009]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:22:17 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 82. Oct 16 17:22:17 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:22:17 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:22:17 bcik go-librespot[14789]: go-librespot daemon starting... Oct 16 17:22:17 bcik go-librespot[14790]: time="2026-10-16T17:22:17+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:22:17 bcik go-librespot[14790]: time="2026-10-16T17:22:17+02:00" level=debug msg="app state loaded" Oct 16 17:22:17 bcik go-librespot[14790]: time="2026-10-16T17:22:17+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:22:17 bcik go-librespot[14790]: time="2026-10-16T17:22:17+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 16 17:22:17 bcik go-librespot[14790]: time="2026-10-16T17:22:17+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 16 17:22:17 bcik go-librespot[14790]: time="2026-10-16T17:22:17+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 16 17:22:17 bcik go-librespot[14790]: time="2026-10-16T17:22:17+02:00" level=info msg="zeroconf server listening on port 34839" Oct 16 17:22:17 bcik go-librespot[14790]: time="2026-10-16T17:22:17+02:00" level=debug msg="obtained new client token: AAHt6ieDSC0+QzN8HZ6+10WvQ5H+YFDmLGkN+LHcCj1tQZo8se5E+kUZm83KnyFPR8Lml5vtRn1fo1PXdql4ABc9vLhcjxpVftW0ky3mUnlDq2DD1GQgJGSbcNVNbW2d0wI572FpeiP0VbnDcDC7A4QbcQayWXil7wpEgZlnZHgdVeq2ZhKB8eogIuBiUJwxHhBgwekZ1VzwsFUFuLYP3GlnKVoHdLBP345XREJtXBssEXOxMwwD8H0=" Oct 16 17:22:18 bcik go-librespot[14790]: time="2026-10-16T17:22:18+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:22:18 bcik go-librespot[14790]: time="2026-10-16T17:22:18+02:00" level=debug msg="completed keyexchange" Oct 16 17:22:18 bcik go-librespot[14790]: time="2026-10-16T17:22:18+02:00" level=debug msg="completed challenge" Oct 16 17:22:18 bcik go-librespot[14790]: time="2026-10-16T17:22:18+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:22:18 bcik go-librespot[14790]: time="2026-10-16T17:22: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 16 17:22:18 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:22:18 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:22:18 bcik volumio[14009]: info: Initializing connection to go-librespot Websocket Oct 16 17:22:18 bcik volumio[14009]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:22:21 bcik volumio[14009]: info: Initializing connection to go-librespot Websocket Oct 16 17:22:21 bcik volumio[14009]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:22:21 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 83. Oct 16 17:22:21 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:22:21 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:22:21 bcik go-librespot[14799]: go-librespot daemon starting... Oct 16 17:22:21 bcik go-librespot[14800]: time="2026-10-16T17:22:21+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:22:21 bcik go-librespot[14800]: time="2026-10-16T17:22:21+02:00" level=debug msg="app state loaded" Oct 16 17:22:21 bcik go-librespot[14800]: time="2026-10-16T17:22:21+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:22:21 bcik go-librespot[14800]: time="2026-10-16T17:22:21+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 16 17:22:21 bcik go-librespot[14800]: time="2026-10-16T17:22:21+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 16 17:22:21 bcik go-librespot[14800]: time="2026-10-16T17:22:21+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 16 17:22:21 bcik go-librespot[14800]: time="2026-10-16T17:22:21+02:00" level=info msg="zeroconf server listening on port 41687" Oct 16 17:22:21 bcik go-librespot[14800]: time="2026-10-16T17:22:21+02:00" level=debug msg="obtained new client token: AAGq1pJv4OCBHuUS8n1m8Lws/ZnE4zhkNajIV7fNghNDtx67Uyafk8H8RuIU/TuvxazOkBALWeZig7QlzEUzoLzbOb51TGFNSyJEKxt7my9zTaaZ8b+LpI9bfs2CXbdezHQabiImKxUy+pM9lHdXzOEgxHQXYObewJ6FGMFMnmr9N4eV8pAsME6ohpXZ3TM3+Pj9LdZin9lV96MhtmryDAirv2eeCRqK1k03O2RC+5GsovtSM68wu3c=" Oct 16 17:22:21 bcik go-librespot[14800]: time="2026-10-16T17:22:21+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:22:21 bcik go-librespot[14800]: time="2026-10-16T17:22:21+02:00" level=debug msg="completed keyexchange" Oct 16 17:22:21 bcik go-librespot[14800]: time="2026-10-16T17:22:21+02:00" level=debug msg="completed challenge" Oct 16 17:22:21 bcik go-librespot[14800]: time="2026-10-16T17:22:21+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:22:21 bcik go-librespot[14800]: time="2026-10-16T17:22:21+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 16 17:22:21 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:22:21 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:22:24 bcik volumio[14009]: info: Initializing connection to go-librespot Websocket Oct 16 17:22:24 bcik volumio[14009]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:22:24 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 84. Oct 16 17:22:24 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:22:24 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:22:24 bcik go-librespot[14810]: go-librespot daemon starting... Oct 16 17:22:24 bcik go-librespot[14811]: time="2026-10-16T17:22:24+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:22:24 bcik go-librespot[14811]: time="2026-10-16T17:22:24+02:00" level=debug msg="app state loaded" Oct 16 17:22:24 bcik go-librespot[14811]: time="2026-10-16T17:22:24+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:22:25 bcik go-librespot[14811]: time="2026-10-16T17:22: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-gew1.spotify.com:80]" Oct 16 17:22:25 bcik go-librespot[14811]: time="2026-10-16T17:22:25+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 16 17:22:25 bcik go-librespot[14811]: time="2026-10-16T17:22:25+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 16 17:22:25 bcik go-librespot[14811]: time="2026-10-16T17:22:25+02:00" level=info msg="zeroconf server listening on port 41675" Oct 16 17:22:25 bcik go-librespot[14811]: time="2026-10-16T17:22:25+02:00" level=debug msg="obtained new client token: AAGGZVms7cdu5KE/jh6qj5PvpftcRBvDI15Sxhv5nI1zYouZwjIX7xUg8wL1fgLKc6nsnDNvGcpmVyB+eAM4iK2Ok+jSvIaXmPbN5KvEYrzwyCA+Q1fKHAFyIA0chZ6IXDUHctJ7pcAfROKZDVGmosk080XK3IizZCbav87unY5DCCwGrIeqyux9XFhB07BXIHIarMx6wqEW8hPtO5ph6eOpmLnnGY8BpoJZu5WJXU2B/5CZlLM1" Oct 16 17:22:25 bcik go-librespot[14811]: time="2026-10-16T17:22:25+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:22:25 bcik go-librespot[14811]: time="2026-10-16T17:22:25+02:00" level=debug msg="completed keyexchange" Oct 16 17:22:25 bcik go-librespot[14811]: time="2026-10-16T17:22:25+02:00" level=debug msg="completed challenge" Oct 16 17:22:25 bcik go-librespot[14811]: time="2026-10-16T17:22:25+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:22:25 bcik go-librespot[14811]: time="2026-10-16T17:22: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 16 17:22:25 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:22:25 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:22:27 bcik volumio[14009]: info: Initializing connection to go-librespot Websocket Oct 16 17:22:27 bcik volumio[14009]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:22:28 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 85. Oct 16 17:22:28 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:22:28 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:22:28 bcik go-librespot[14834]: go-librespot daemon starting... Oct 16 17:22:28 bcik go-librespot[14835]: time="2026-10-16T17:22:28+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:22:28 bcik go-librespot[14835]: time="2026-10-16T17:22:28+02:00" level=debug msg="app state loaded" Oct 16 17:22:28 bcik go-librespot[14835]: time="2026-10-16T17:22:28+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:22:28 bcik go-librespot[14835]: time="2026-10-16T17:22:28+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 16 17:22:28 bcik go-librespot[14835]: time="2026-10-16T17:22:28+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 16 17:22:28 bcik go-librespot[14835]: time="2026-10-16T17:22:28+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 16 17:22:28 bcik go-librespot[14835]: time="2026-10-16T17:22:28+02:00" level=info msg="zeroconf server listening on port 46675" Oct 16 17:22:28 bcik go-librespot[14835]: time="2026-10-16T17:22:28+02:00" level=debug msg="obtained new client token: AAE0W7HlDWpNZdYYI5Q/152+f6OB7CTENZ0qW1t4hIhcol/tjffJ6fhe3bX4UcwkNtDE1IcqFsOKazBeIQ977l5DAWF23nqrz1jT5Ni7YXxKKii9kkfVXaxa0n1RGGkm5Tg5MQU3Ai2g2Qni5O1FKCLRr0pANl99n6UTnSJoVHZ5/cdkMQlQ6xA8ZmfQKYQuTElSDDgOGcH6kn4V603EitAk7Mh0SOxOlzfBv0yX3IIxqZujuFRfRcc=" Oct 16 17:22:28 bcik go-librespot[14835]: time="2026-10-16T17:22:28+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:22:28 bcik go-librespot[14835]: time="2026-10-16T17:22:28+02:00" level=debug msg="completed keyexchange" Oct 16 17:22:28 bcik go-librespot[14835]: time="2026-10-16T17:22:28+02:00" level=debug msg="completed challenge" Oct 16 17:22:28 bcik go-librespot[14835]: time="2026-10-16T17:22:28+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:22:28 bcik go-librespot[14835]: time="2026-10-16T17:22:28+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 16 17:22:28 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:22:28 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:22:30 bcik volumio[14009]: info: Initializing connection to go-librespot Websocket Oct 16 17:22:30 bcik volumio[14009]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:22:32 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 86. Oct 16 17:22:32 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:22:32 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:22:32 bcik go-librespot[14844]: go-librespot daemon starting... Oct 16 17:22:32 bcik go-librespot[14845]: time="2026-10-16T17:22:32+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:22:32 bcik go-librespot[14845]: time="2026-10-16T17:22:32+02:00" level=debug msg="app state loaded" Oct 16 17:22:32 bcik go-librespot[14845]: time="2026-10-16T17:22:32+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:22:32 bcik go-librespot[14845]: time="2026-10-16T17:22: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Oct 16 17:22:32 bcik go-librespot[14845]: time="2026-10-16T17:22:32+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 16 17:22:32 bcik go-librespot[14845]: time="2026-10-16T17:22:32+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 16 17:22:32 bcik go-librespot[14845]: time="2026-10-16T17:22:32+02:00" level=info msg="zeroconf server listening on port 44507" Oct 16 17:22:32 bcik go-librespot[14845]: time="2026-10-16T17:22:32+02:00" level=debug msg="obtained new client token: AAFou8POErM2xINLdgx81qsdSRunI9NJsu8xvzBqlUlvrxnB4/43rCK8I/HdDP+bcuLoasNjZLkI2UOuyjgRQrYcE1hncEY7P6JUfNso7FY/5MaMFnJ0AIeSwNBhiWD3wAoYjuvJR2TJzsdhou+BSdEWIBwvOftfMcIpUDQgoc3QOmUOKYvXBW9VFRr0ReB+tjGzh5oEb45In9wGRR3jQ/EEOWfsNk30MeW+lvr2OBdLj/su/iti" Oct 16 17:22:32 bcik go-librespot[14845]: time="2026-10-16T17:22:32+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:22:32 bcik go-librespot[14845]: time="2026-10-16T17:22:32+02:00" level=debug msg="completed keyexchange" Oct 16 17:22:32 bcik go-librespot[14845]: time="2026-10-16T17:22:32+02:00" level=debug msg="completed challenge" Oct 16 17:22:32 bcik go-librespot[14845]: time="2026-10-16T17:22:32+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:22:32 bcik go-librespot[14845]: time="2026-10-16T17:22: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 16 17:22:32 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:22:32 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:22:33 bcik volumio[14009]: info: Initializing connection to go-librespot Websocket Oct 16 17:22:33 bcik volumio[14009]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:22:35 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 87. Oct 16 17:22:35 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:22:35 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:22:35 bcik go-librespot[14854]: go-librespot daemon starting... Oct 16 17:22:35 bcik go-librespot[14855]: time="2026-10-16T17:22:35+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:22:35 bcik go-librespot[14855]: time="2026-10-16T17:22:35+02:00" level=debug msg="app state loaded" Oct 16 17:22:35 bcik go-librespot[14855]: time="2026-10-16T17:22:35+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:22:35 bcik go-librespot[14855]: time="2026-10-16T17:22:35+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 16 17:22:35 bcik go-librespot[14855]: time="2026-10-16T17:22:35+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 16 17:22:35 bcik go-librespot[14855]: time="2026-10-16T17:22:35+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 16 17:22:35 bcik go-librespot[14855]: time="2026-10-16T17:22:35+02:00" level=info msg="zeroconf server listening on port 43089" Oct 16 17:22:35 bcik go-librespot[14855]: time="2026-10-16T17:22:35+02:00" level=debug msg="obtained new client token: AAGsyXH9viEQytdPTrt8xSCw42p5bs+YNZ8xSMguPdztfYDvZyMaijQSFXWSMOB4LEoM+tyoNH4hXThhXwRHo6UiuYArUmnsFsAq+8+1IoNSNaWhiGcsSQJVJpF/Mp35VLgdWcpSN8IkufboIYt1P7sMPhhKAcNdyB6lYzUSPAUarQTM/uUMs5205RCVhTuY/96Nu8rnPTwe7dVSFu+CuVBCdbMtDcssbIyiLg75AJjo35vY+UxJQ5w=" Oct 16 17:22:35 bcik go-librespot[14855]: time="2026-10-16T17:22:35+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:22:35 bcik go-librespot[14855]: time="2026-10-16T17:22:35+02:00" level=debug msg="completed keyexchange" Oct 16 17:22:35 bcik go-librespot[14855]: time="2026-10-16T17:22:35+02:00" level=debug msg="completed challenge" Oct 16 17:22:35 bcik go-librespot[14855]: time="2026-10-16T17:22:35+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:22:35 bcik go-librespot[14855]: time="2026-10-16T17:22:35+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 16 17:22:35 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:22:35 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:22:36 bcik volumio[14009]: info: Initializing connection to go-librespot Websocket Oct 16 17:22:36 bcik volumio[14009]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:22:39 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 88. Oct 16 17:22:39 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:22:39 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:22:39 bcik go-librespot[14879]: go-librespot daemon starting... Oct 16 17:22:39 bcik go-librespot[14880]: time="2026-10-16T17:22:39+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:22:39 bcik go-librespot[14880]: time="2026-10-16T17:22:39+02:00" level=debug msg="app state loaded" Oct 16 17:22:39 bcik go-librespot[14880]: time="2026-10-16T17:22:39+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:22:39 bcik go-librespot[14880]: time="2026-10-16T17:22: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 16 17:22:39 bcik go-librespot[14880]: time="2026-10-16T17:22: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 16 17:22:39 bcik go-librespot[14880]: time="2026-10-16T17:22: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 16 17:22:39 bcik go-librespot[14880]: time="2026-10-16T17:22:39+02:00" level=info msg="zeroconf server listening on port 40713" Oct 16 17:22:39 bcik go-librespot[14880]: time="2026-10-16T17:22:39+02:00" level=debug msg="obtained new client token: AAGd5beR3/IQhjAGW3dmfS7bEMRueL7pSorv5/rUPHrj4+v5q7nBzMObYrQcTbPHIpk+KY7aI2ApPISZ2lhMn1zZTAu4wlKTuvA5IcqHdguq46Z8j6ztBEIjx04j4RTHAEfhsgXuDV+TJ9Od6u3GKrbVa0cBKgQwZxGIkxGt6+zcM+54sJcqyQxVCiVU9QUfdhZqYrhzicIulhPUe6/y3k4nGAM17doX8n+GPx3GY47e/eO7v865" Oct 16 17:22:39 bcik go-librespot[14880]: time="2026-10-16T17:22:39+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:22:39 bcik volumio[14009]: info: Initializing connection to go-librespot Websocket Oct 16 17:22:39 bcik go-librespot[14880]: time="2026-10-16T17:22:39+02:00" level=debug msg="new websocket client" Oct 16 17:22:39 bcik volumio[14009]: info: Connection to go-librespot Websocket established Oct 16 17:22:39 bcik go-librespot[14880]: time="2026-10-16T17:22:39+02:00" level=debug msg="completed keyexchange" Oct 16 17:22:39 bcik go-librespot[14880]: time="2026-10-16T17:22:39+02:00" level=debug msg="completed challenge" Oct 16 17:22:39 bcik go-librespot[14880]: time="2026-10-16T17:22:39+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:22:39 bcik go-librespot[14880]: time="2026-10-16T17:22: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 16 17:22:39 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:22:39 bcik volumio[14009]: info: Connection to go-librespot Websocket closed Oct 16 17:22:39 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:22:42 bcik volumio[14009]: info: Getting Spotify volume Oct 16 17:22:42 bcik volumio[14009]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 16 17:22:42 bcik volumio[14009]: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:22:42 bcik volumio[14009]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Oct 16 17:22:42 bcik volumio[14009]: errno: -111, Oct 16 17:22:42 bcik volumio[14009]: code: 'ECONNREFUSED', Oct 16 17:22:42 bcik volumio[14009]: syscall: 'connect', Oct 16 17:22:42 bcik volumio[14009]: address: '127.0.0.1', Oct 16 17:22:42 bcik volumio[14009]: port: 9879, Oct 16 17:22:42 bcik volumio[14009]: response: undefined Oct 16 17:22:42 bcik volumio[14009]: } Oct 16 17:22:42 bcik volumio[14009]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 16 17:22:42 bcik sudo[14903]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-16 17:21' Oct 16 17:22:42 bcik sudo[14903]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:22:42 bcik sudo[14903]: pam_unix(sudo:session): session closed for user root Oct 16 17:22:42 bcik volumio-remote-updater[9031]: [2026-10-16 17:22:42] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Oct 16 17:22:42 bcik volumio-remote-updater[9031]: [2026-10-16 17:22:42] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Oct 16 17:22:42 bcik volumio5-onboarding[5439]: time=2026-10-16T17:22:42.525+02:00 level=ERROR msg="failed reading message" error="websocket: close 1006 (abnormal closure): unexpected EOF" Oct 16 17:22:42 bcik systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:22:42 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 89. Oct 16 17:22:42 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:22:42 bcik volumio5-onboarding[5439]: time=2026-10-16T17:22:42.528+02:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Oct 16 17:22:42 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:22:42 bcik go-librespot[14908]: go-librespot daemon starting... Oct 16 17:22:42 bcik systemd[1]: volumio.service: Failed with result 'exit-code'. Oct 16 17:22:42 bcik systemd[1]: volumio.service: Consumed 6.911s CPU time. Oct 16 17:22:42 bcik systemd[1]: Started dynamicswap.service - dynamicswap service. Oct 16 17:22:42 bcik go-librespot[14912]: time="2026-10-16T17:22:42+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:22:42 bcik go-librespot[14912]: time="2026-10-16T17:22:42+02:00" level=debug msg="app state loaded" Oct 16 17:22:42 bcik go-librespot[14912]: time="2026-10-16T17:22:42+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:22:42 bcik systemd[1]: dynamicswap.service: Deactivated successfully. Oct 16 17:22:42 bcik systemd[1]: volumio.service: Scheduled restart job, restart counter is at 27695. Oct 16 17:22:42 bcik systemd[1]: Started dynamicswap.service - dynamicswap service. Oct 16 17:22:42 bcik systemd[1]: Stopped volumio.service - Volumio Backend Module. Oct 16 17:22:42 bcik systemd[1]: volumio.service: Consumed 6.911s CPU time. Oct 16 17:22:42 bcik systemd[1]: Started volumio.service - Volumio Backend Module. Oct 16 17:22:42 bcik go-librespot[14912]: time="2026-10-16T17:22:42+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 16 17:22:42 bcik go-librespot[14912]: time="2026-10-16T17:22:42+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 16 17:22:42 bcik go-librespot[14912]: time="2026-10-16T17:22:42+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 16 17:22:42 bcik systemd[1]: dynamicswap.service: Deactivated successfully. Oct 16 17:22:42 bcik go-librespot[14912]: time="2026-10-16T17:22:42+02:00" level=info msg="zeroconf server listening on port 45107" Oct 16 17:22:42 bcik go-librespot[14912]: time="2026-10-16T17:22:42+02:00" level=debug msg="obtained new client token: AAE0OTPLQqhn15Vk+TgDKv+RuTAJZDepp6pkKZnXcx6/qWNMht/47WVgD0n+eRHOA+gJAo8ThiAxWpmbEuW9DKQrnq18lC4xAow8ixsaKU63nzQ7foOFUsAi3bSHvGB9YidYZiCovjBa2D64V5us2DRwlcQ8IU5h8mw4NmRbucaVmG/R/LJyTf54po2POa4e4PZ1dqXcUdwx2u0UbtAoc69SPgVlUcu73aIXDhjnFS22iN3w3Qwa7Yo=" Oct 16 17:22:42 bcik go-librespot[14912]: time="2026-10-16T17:22:42+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:22:42 bcik go-librespot[14912]: time="2026-10-16T17:22:42+02:00" level=debug msg="completed keyexchange" Oct 16 17:22:42 bcik go-librespot[14912]: time="2026-10-16T17:22:42+02:00" level=debug msg="completed challenge" Oct 16 17:22:42 bcik go-librespot[14912]: time="2026-10-16T17:22:42+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:22:43 bcik volumio[14927]: info: ------------------------------------------- Oct 16 17:22:43 bcik volumio[14927]: info: ----- Volumio3 ---- Oct 16 17:22:43 bcik volumio[14927]: info: ------------------------------------------- Oct 16 17:22:43 bcik volumio[14927]: info: ----- System startup ---- Oct 16 17:22:43 bcik volumio[14927]: info: ------------------------------------------- Oct 16 17:22:43 bcik volumio[14927]: info: MYVOLUMIO Environment detected Oct 16 17:22:43 bcik volumio[14927]: info: Plugin folders cleanup Oct 16 17:22:43 bcik volumio[14927]: info: Scanning into folder /volumio/app/plugins/ Oct 16 17:22:43 bcik volumio[14927]: info: Scanning category audio_interface Oct 16 17:22:43 bcik volumio[14927]: info: Scanning category miscellanea Oct 16 17:22:43 bcik volumio[14927]: info: Scanning category music_service Oct 16 17:22:43 bcik volumio[14927]: info: Scanning category plugins.json Oct 16 17:22:43 bcik volumio[14927]: info: Scanning category system_controller Oct 16 17:22:43 bcik volumio[14927]: info: Scanning category user_interface Oct 16 17:22:43 bcik volumio[14927]: info: Scanning into folder /data/plugins/ Oct 16 17:22:43 bcik volumio[14927]: info: Scanning category music_service Oct 16 17:22:43 bcik volumio[14927]: info: Plugin folders cleanup completed Oct 16 17:22:43 bcik volumio[14927]: info: ------------------------------------------- Oct 16 17:22:43 bcik volumio[14927]: info: ----- Core plugins startup ---- Oct 16 17:22:43 bcik volumio[14927]: info: ------------------------------------------- Oct 16 17:22:43 bcik volumio[14927]: info: Loading plugins from folder /volumio/app/plugins/ Oct 16 17:22:43 bcik volumio[14927]: info: Adding plugin upnp to MyMusic Plugins Oct 16 17:22:43 bcik volumio[14927]: info: Adding plugin airplay_emulation to MyMusic Plugins Oct 16 17:22:43 bcik volumio[14927]: info: Adding plugin upnp_browser to MyMusic Plugins Oct 16 17:22:43 bcik volumio[14927]: info: Loading plugins from folder /data/plugins/ Oct 16 17:22:43 bcik volumio[14927]: info: Loading plugin "system"... Oct 16 17:22:43 bcik volumio[14927]: info: Loading plugin "appearance"... Oct 16 17:22:43 bcik go-librespot[14912]: time="2026-10-16T17:22: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 16 17:22:43 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:22:43 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:22:43 bcik volumio[14927]: info: Loading plugin "network"... Oct 16 17:22:43 bcik volumio[14927]: info: Refreshing Cached IP Addresses Oct 16 17:22:43 bcik sudo[14957]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 16 17:22:43 bcik sudo[14957]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:22:43 bcik sudo[14959]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 16 17:22:43 bcik sudo[14959]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:22:43 bcik sudo[14957]: pam_unix(sudo:session): session closed for user root Oct 16 17:22:43 bcik sudo[14959]: pam_unix(sudo:session): session closed for user root Oct 16 17:22:43 bcik volumio[14927]: info: Loading plugin "services"... Oct 16 17:22:43 bcik volumio[14927]: info: Loading plugin "volumio5onboarding"... Oct 16 17:22:43 bcik volumio[14927]: info: Loading plugin "alsa_controller"... Oct 16 17:22:43 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 16 17:22:43 bcik volumio[14927]: info: Loading plugin "wizard"... Oct 16 17:22:43 bcik volumio[14927]: info: Loading plugin "networkfs"... Oct 16 17:22:43 bcik volumio[14927]: info: Starting Udev Watcher for removable devices Oct 16 17:22:43 bcik volumio[14927]: info: Ignoring mount for partition: boot Oct 16 17:22:43 bcik volumio[14927]: info: Ignoring mount for partition: volumio Oct 16 17:22:43 bcik volumio[14927]: info: Ignoring mount for partition: volumio_data Oct 16 17:22:43 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 16 17:22:43 bcik volumio[14927]: info: Loading plugin "volumio_command_line_client"... Oct 16 17:22:43 bcik volumio[14927]: info: Loading plugin "upnp"... Oct 16 17:22:43 bcik volumio[14927]: info: [1792164163619] Starting Upmpd Daemon Oct 16 17:22:43 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 16 17:22:43 bcik volumio[14927]: info: Loading plugin "my_music"... Oct 16 17:22:43 bcik volumio[14927]: info: Loading plugin "mpd"... Oct 16 17:22:43 bcik volumio[14927]: info: Loading plugin "upnp_browser"... Oct 16 17:22:43 bcik volumio[14927]: info: Starting UPNP Browser Oct 16 17:22:43 bcik volumio[14927]: info: Loading plugin "alarm-clock"... Oct 16 17:22:44 bcik volumio[14927]: info: Loading plugin "airplay_emulation"... Oct 16 17:22:44 bcik volumio[14927]: info: Starting Shairport Sync Oct 16 17:22:44 bcik volumio[14927]: info: Loading plugin "last_100"... Oct 16 17:22:44 bcik volumio[14927]: info: Loading plugin "webradio"... Oct 16 17:22:44 bcik volumio[14927]: info: Loading plugin "i2s_dacs"... Oct 16 17:22:44 bcik volumio[14927]: info: Loading plugin "volumiodiscovery"... Oct 16 17:22:44 bcik volumio[14927]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 16 17:22:44 bcik node[14927]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 16 17:22:44 bcik volumio[14927]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 16 17:22:44 bcik node[14927]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 16 17:22:44 bcik volumio[14927]: *** WARNING *** For more information see Oct 16 17:22:44 bcik node[14927]: *** WARNING *** For more information see Oct 16 17:22:44 bcik volumio[14927]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 16 17:22:44 bcik node[14927]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 16 17:22:44 bcik volumio[14927]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 16 17:22:44 bcik node[14927]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 16 17:22:44 bcik volumio[14927]: *** WARNING *** For more information see Oct 16 17:22:44 bcik volumio[14927]: info: Applying required configuration parameters for plugin volumiodiscovery Oct 16 17:22:44 bcik volumio[14927]: info: Discovery: Started advertising with name: Bącik Oct 16 17:22:44 bcik node[14927]: *** WARNING *** For more information see Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 16 17:22:44 bcik volumio[14927]: info: Loading plugin "spop"... Oct 16 17:22:44 bcik volumio[14927]: info: Loading plugin "outputs"... Oct 16 17:22:44 bcik volumio[14927]: info: Loading plugin "albumart"... Oct 16 17:22:44 bcik volumio[14927]: info: Plugin example_plugin is not enabled Oct 16 17:22:44 bcik volumio[14927]: info: Loading plugin "inputs"... Oct 16 17:22:44 bcik volumio[14927]: info: Loading plugin "updater_comm"... Oct 16 17:22:44 bcik volumio[14927]: info: Plugin mpdemulation is not enabled Oct 16 17:22:44 bcik volumio[14927]: info: Loading plugin "rest_api"... Oct 16 17:22:44 bcik volumio[14927]: info: Loading plugin "websocket"... Oct 16 17:22:44 bcik volumio[14927]: info: Starting Socket.io Server version 1.7.4 Oct 16 17:22:44 bcik volumio[14927]: info: Loading plugin "radio_browser"... Oct 16 17:22:44 bcik volumio[14989]: Forking 3 albumart workers Oct 16 17:22:44 bcik volumio[14927]: info: Loading i18n strings for locale pl Oct 16 17:22:44 bcik volumio[14927]: Updating browse sources language Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::initPlayerControls Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 16 17:22:44 bcik volumio[14927]: Express server listening on port 3000 Oct 16 17:22:44 bcik volumio[14927]: [Metrics] WebUI: 1s 295.01ms Oct 16 17:22:44 bcik volumio[14927]: info: CoreStateMachine::resetVolumioState Oct 16 17:22:44 bcik volumio[14927]: info: CoreStateMachine::getcurrentVolume Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::volumioRetrievevolume Oct 16 17:22:44 bcik volumio[14927]: info: Volumio Network Manager: Network status updated: 1 Oct 16 17:22:44 bcik volumio[14927]: verbose: New 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 16 17:22:44 bcik volumio[14927]: verbose: New 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 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:22:44 bcik volumio[14927]: info: Reloading queue from file Oct 16 17:22:44 bcik volumio[14927]: info: CoreStateMachine::setRepeat false single undefined Oct 16 17:22:44 bcik volumio[14927]: info: CoreStateMachine::pushState Oct 16 17:22:44 bcik volumio[14927]: info: CorePlayQueue::getTrack 0 Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::volumioPushState Oct 16 17:22:44 bcik volumio[14927]: info: CoreStateMachine::setRandom false Oct 16 17:22:44 bcik volumio[14927]: info: CoreStateMachine::pushState Oct 16 17:22:44 bcik volumio[14927]: info: CorePlayQueue::getTrack 0 Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::volumioPushState Oct 16 17:22:44 bcik volumio[14927]: info: VolumeController:: Volume=41 Mute =false Oct 16 17:22:44 bcik volumio[14927]: info: CoreStateMachine::pushState Oct 16 17:22:44 bcik volumio[14927]: info: CorePlayQueue::getTrack 0 Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::volumioPushState Oct 16 17:22:44 bcik volumio[14927]: info: CoreStateMachine::updateTrackBlock Oct 16 17:22:44 bcik volumio[14927]: info: CorePlayQueue::getTrackBlock Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::volumioRetrievevolume Oct 16 17:22:44 bcik volumio[14927]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Oct 16 17:22:44 bcik volumio[14927]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04171 Oct 16 17:22:44 bcik volumio[14927]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Oct 16 17:22:44 bcik volumio[14927]: verbose: New 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 16 17:22:44 bcik volumio[14927]: info: Setting Device type: Raspberry PI Oct 16 17:22:44 bcik volumio[14927]: info: Completed loading Core Plugins Oct 16 17:22:44 bcik volumio[14927]: info: Preparing to generate the ALSA configuration file Oct 16 17:22:44 bcik volumio[14927]: verbose: New 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 16 17:22:44 bcik volumio[14927]: info: VolumeController:: Volume=41 Mute =false Oct 16 17:22:44 bcik volumio[14927]: info: CoreStateMachine::pushState Oct 16 17:22:44 bcik volumio[14927]: info: CorePlayQueue::getTrack 0 Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::volumioPushState Oct 16 17:22:44 bcik volumio[14927]: verbose: New 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 16 17:22:44 bcik volumio[14927]: info: Asound.conf file unchanged, so no further update is needed Oct 16 17:22:44 bcik volumio[14927]: info: Output device has changed, restarting MPD Oct 16 17:22:44 bcik volumio[14927]: info: Output device has changed, restarting Shairport Sync Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:22:44 bcik sudo[15045]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 16 17:22:44 bcik sudo[15045]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:22:44 bcik sudo[15045]: pam_unix(sudo:session): session closed for user root Oct 16 17:22:44 bcik sudo[15046]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 16 17:22:44 bcik sudo[15046]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:22:44 bcik volumio[14927]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 16 17:22:44 bcik volumio[14927]: info: ___________ START PLUGINS ___________ Oct 16 17:22:44 bcik volumio[14927]: info: ControllerMpd::onStart: Initializing MPD Oct 16 17:22:44 bcik volumio[14927]: info: Creating MPD Configuration file Oct 16 17:22:44 bcik systemd[1]: Stopping mpd.service - Music Player Daemon... Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 16 17:22:44 bcik volumio[14927]: info: [1792164164552] CoreMusicLibrary::Adding element Serwery Mediów Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 17:22:44 bcik volumio[14927]: info: UPNP Browser: Client initialized successfully Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:22:44 bcik sudo[15054]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Oct 16 17:22:44 bcik sudo[15054]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:22:44 bcik sudo[15058]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 16 17:22:44 bcik sudo[15058]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:22:44 bcik sudo[15056]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 16 17:22:44 bcik sudo[15056]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:22:44 bcik systemd[1]: mpd.service: Deactivated successfully. Oct 16 17:22:44 bcik systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 16 17:22:44 bcik sudo[15056]: pam_unix(sudo:session): session closed for user root Oct 16 17:22:44 bcik volumio[14927]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:22:44 bcik systemd[1]: mpd.socket: Deactivated successfully. Oct 16 17:22:44 bcik systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 16 17:22:44 bcik systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 16 17:22:44 bcik volumio[14927]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 16 17:22:44 bcik volumio[14927]: info: [1792164164593] CoreMusicLibrary::Adding element Last_100 Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 17:22:44 bcik systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 16 17:22:44 bcik volumio[14927]: info: [1792164164595] CoreMusicLibrary::Adding element Webradio Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 17:22:44 bcik systemd[1]: Starting mpd.service - Music Player Daemon... Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 16 17:22:44 bcik volumio[14927]: info: Initializing BBC Radios Oct 16 17:22:44 bcik systemd[1]: mpd.service: Deactivated successfully. Oct 16 17:22:44 bcik systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 16 17:22:44 bcik systemd[1]: mpd.socket: Deactivated successfully. Oct 16 17:22:44 bcik systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 16 17:22:44 bcik systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 16 17:22:44 bcik sudo[15054]: pam_unix(sudo:session): session closed for user root Oct 16 17:22:44 bcik systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 16 17:22:44 bcik systemd[1]: Starting mpd.service - Music Player Daemon... Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:22:44 bcik volumio[14927]: info: Creating Spotify config file Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:22:44 bcik sudo[15076]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 16 17:22:44 bcik sudo[15076]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 16 17:22:44 bcik sudo[15076]: pam_unix(sudo:session): session closed for user root Oct 16 17:22:44 bcik volumio[14999]: Starting albumart workers Oct 16 17:22:44 bcik volumio[15001]: Starting albumart workers Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 16 17:22:44 bcik volumio[14927]: info: [1792164164757] CoreMusicLibrary::Adding element Radio Browser Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 17:22:44 bcik volumio[14927]: Cannot find translation for source Radio Browser Oct 16 17:22:44 bcik volumio[14927]: info: Volumio Calling Home Oct 16 17:22:44 bcik volumio[15000]: Starting albumart workers Oct 16 17:22:44 bcik volumio[14927]: verbose: New 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 16 17:22:44 bcik volumio[14927]: info: MPD Permissions set Oct 16 17:22:44 bcik volumio[14927]: info: MPD Permissions set Oct 16 17:22:44 bcik volumio[14927]: 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 16 17:22:44 bcik volumio[14927]: info: Spotify config file written Oct 16 17:22:44 bcik sudo[15100]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Oct 16 17:22:44 bcik sudo[15100]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:22:44 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:22:44 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:22:44 bcik go-librespot[15108]: go-librespot daemon starting... Oct 16 17:22:44 bcik sudo[15100]: pam_unix(sudo:session): session closed for user root Oct 16 17:22:44 bcik volumio[14927]: verbose: New 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 16 17:22:44 bcik go-librespot[15109]: time="2026-10-16T17:22:44+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:22:44 bcik go-librespot[15109]: time="2026-10-16T17:22:44+02:00" level=debug msg="app state loaded" Oct 16 17:22:44 bcik go-librespot[15109]: time="2026-10-16T17:22:44+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:22:44 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:22:44 bcik volumio[14927]: info: No need to fix Spotify hosts Oct 16 17:22:45 bcik volumio[14927]: info: Volumio called home Oct 16 17:22:45 bcik volumio[14927]: verbose: New 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 16 17:22:45 bcik volumio[14927]: info: Starting Shairport Sync Oct 16 17:22:45 bcik volumio[14927]: info: Starting Shairport Sync Oct 16 17:22:45 bcik volumio[14927]: info: Starting Shairport Sync Oct 16 17:22:45 bcik sudo[15134]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 16 17:22:45 bcik sudo[15134]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:22:45 bcik sudo[15136]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 16 17:22:45 bcik sudo[15136]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:22:45 bcik systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 16 17:22:45 bcik systemd[1]: shairport-sync.service: Deactivated successfully. Oct 16 17:22:45 bcik systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 16 17:22:45 bcik systemd[1]: shairport-sync.service: Consumed 1.623s CPU time. Oct 16 17:22:45 bcik sudo[15139]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 16 17:22:45 bcik sudo[15139]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:22:45 bcik volumio[14927]: info: Discovery: adding f1ed5fb6-e21d-47c8-819b-29842600355e Oct 16 17:22:45 bcik volumio[14927]: info: Discovery: Found device Bącik Oct 16 17:22:45 bcik volumio[14927]: info: CoreCommandRouter::volumioGetState Oct 16 17:22:45 bcik volumio[14927]: info: CorePlayQueue::getTrack 0 Oct 16 17:22:45 bcik volumio[14927]: info: Discovery: this is already registered, f1ed5fb6-e21d-47c8-819b-29842600355e Oct 16 17:22:45 bcik volumio[14927]: info: Discovery: Found device Bącik Oct 16 17:22:45 bcik volumio[14927]: info: CoreCommandRouter::volumioGetState Oct 16 17:22:45 bcik volumio[14927]: info: CorePlayQueue::getTrack 0 Oct 16 17:22:45 bcik volumio[14927]: verbose: New 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 16 17:22:45 bcik systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 16 17:22:45 bcik volumio[14927]: verbose: New 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 16 17:22:45 bcik sudo[15134]: pam_unix(sudo:session): session closed for user root Oct 16 17:22:45 bcik volumio[14927]: info: CoreCommandRouter::volumioGetState Oct 16 17:22:45 bcik volumio[14927]: info: CorePlayQueue::getTrack 0 Oct 16 17:22:45 bcik systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 16 17:22:45 bcik systemd[1]: shairport-sync.service: Deactivated successfully. Oct 16 17:22:45 bcik volumio[14927]: verbose: New 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 16 17:22:45 bcik systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 16 17:22:45 bcik go-librespot[15109]: time="2026-10-16T17:22:45+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 16 17:22:45 bcik go-librespot[15109]: time="2026-10-16T17:22:45+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 16 17:22:45 bcik go-librespot[15109]: time="2026-10-16T17:22:45+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 16 17:22:45 bcik volumio[14927]: info: Shairport-Sync Started Oct 16 17:22:45 bcik volumio[14927]: Error adding Membership: Error: addMembership EINVAL Oct 16 17:22:45 bcik systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 16 17:22:45 bcik volumio[14927]: verbose: New 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 16 17:22:45 bcik sudo[15139]: pam_unix(sudo:session): session closed for user root Oct 16 17:22:45 bcik sudo[15136]: pam_unix(sudo:session): session closed for user root Oct 16 17:22:45 bcik go-librespot[15109]: time="2026-10-16T17:22:45+02:00" level=info msg="zeroconf server listening on port 43417" Oct 16 17:22:45 bcik volumio[14927]: info: An error occurred while refreshing Spotify Token Error: Bad Request Oct 16 17:22:45 bcik volumio[14927]: verbose: New 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 16 17:22:45 bcik volumio[14927]: info: Shairport-Sync Started Oct 16 17:22:45 bcik volumio[14927]: info: Shairport-Sync Started Oct 16 17:22:45 bcik volumio[14927]: verbose: New 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 16 17:22:45 bcik volumio[14927]: verbose: New 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 16 17:22:45 bcik volumio[14927]: verbose: New 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 16 17:22:45 bcik volumio[14927]: verbose: New 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 16 17:22:45 bcik volumio[14927]: verbose: New 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 16 17:22:45 bcik volumio[14927]: verbose: New 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 16 17:22:45 bcik volumio[14927]: verbose: New 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 16 17:22:45 bcik volumio[14927]: verbose: New 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 16 17:22:45 bcik volumio[14927]: verbose: New 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 16 17:22:45 bcik volumio[14927]: verbose: New 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 16 17:22:45 bcik go-librespot[15109]: time="2026-10-16T17:22:45+02:00" level=debug msg="obtained new client token: AAHRWDGUq07Sp+BS1lJOS79NBlJbtbk499sV+isb1IWKOOh0zznWEeI2M1qGvx9QtGkYZsakA42yn0lhCA87/fMJRXqiJ1bZoZojBL83xc1Uwg935FDQERubFya0gaANNtBwLETlhHxSOCesYbB+kGhhj/N0/aAu96oKWtdLoUUOtTP5U2LHfFZaNmiUHbo3GV5IyhJOk4IQNoinXOtFUasKUuv7IJXSqahrXaO2KX58JkRkH43k" Oct 16 17:22:45 bcik volumio[14927]: verbose: New 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 16 17:22:45 bcik volumio[14927]: verbose: New 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 16 17:22:45 bcik volumio[14927]: verbose: New 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 16 17:22:45 bcik volumio[14927]: verbose: New 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 16 17:22:45 bcik volumio5-onboarding[5439]: time=2026-10-16T17:22:45.179+02:00 level=ERROR msg="failed reading message" error="websocket: RSV2 set, bad opcode 13" Oct 16 17:22:45 bcik volumio[14927]: verbose: New 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 16 17:22:45 bcik volumio5-onboarding[5439]: panic: send on closed channel Oct 16 17:22:45 bcik volumio5-onboarding[5439]: goroutine 69511 [running]: Oct 16 17:22:45 bcik volumio5-onboarding[5439]: github.com/VolumioTeam/volumio5-device-gateway/socketio.(*Client).readLoop(0x186e5c0) Oct 16 17:22:45 bcik volumio5-onboarding[5439]: /src/socketio/client.go:161 +0x1f4 Oct 16 17:22:45 bcik volumio5-onboarding[5439]: created by github.com/VolumioTeam/volumio5-device-gateway/socketio.(*Client).connect in goroutine 69542 Oct 16 17:22:45 bcik volumio5-onboarding[5439]: /src/socketio/client.go:134 +0x73c Oct 16 17:22:45 bcik volumio[14927]: verbose: New 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 16 17:22:45 bcik systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=2/INVALIDARGUMENT Oct 16 17:22:45 bcik systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Oct 16 17:22:45 bcik systemd[1]: volumio5-onboarding.service: Consumed 11.033s CPU time. Oct 16 17:22:45 bcik go-librespot[15109]: time="2026-10-16T17:22:45+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 16 17:22:45 bcik go-librespot[15109]: time="2026-10-16T17:22:45+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Oct 16 17:22:45 bcik mpd[15088]: 2026-10-16T17:22:45 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 16 17:22:45 bcik systemd[1]: Started mpd.service - Music Player Daemon. Oct 16 17:22:45 bcik sudo[15046]: pam_unix(sudo:session): session closed for user root Oct 16 17:22:45 bcik sudo[15058]: pam_unix(sudo:session): session closed for user root Oct 16 17:22:45 bcik go-librespot[15109]: time="2026-10-16T17:22:45+02:00" level=debug msg="completed keyexchange" Oct 16 17:22:45 bcik go-librespot[15109]: time="2026-10-16T17:22:45+02:00" level=debug msg="completed challenge" Oct 16 17:22:45 bcik volumio[14927]: info: Completed starting Core Plugins Oct 16 17:22:45 bcik volumio[14927]: info: ------------------------------------------- Oct 16 17:22:45 bcik volumio[14927]: info: ----- MyVolumio plugins startup ---- Oct 16 17:22:45 bcik volumio[14927]: info: ------------------------------------------- Oct 16 17:22:45 bcik volumio[14927]: info: [MyVolumio PluginManager] Fetching plans data.... Oct 16 17:22:45 bcik volumio[14927]: error: MPD error: The expression evaluated to a falsy value: Oct 16 17:22:45 bcik volumio[14927]: assert.ok(self.idling) Oct 16 17:22:45 bcik volumio[14927]: error: The expression evaluated to a falsy value: Oct 16 17:22:45 bcik volumio[14927]: assert.ok(self.idling) Oct 16 17:22:45 bcik volumio[14927]: error: updateQueue error: null Oct 16 17:22:45 bcik volumio[14927]: info: MPD running with PID15088 Oct 16 17:22:45 bcik volumio[14927]: ,establishing connection Oct 16 17:22:45 bcik volumio[14927]: error: updateQueue error: null Oct 16 17:22:45 bcik go-librespot[15109]: time="2026-10-16T17:22:45+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:22:45 bcik systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 363. Oct 16 17:22:45 bcik systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Oct 16 17:22:45 bcik systemd[1]: volumio5-onboarding.service: Consumed 11.033s CPU time. Oct 16 17:22:45 bcik systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Oct 16 17:22:45 bcik volumio5-onboarding[15165]: time=2026-10-16T17:22:45.326+02:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Oct 16 17:22:45 bcik volumio[14927]: verbose: New 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 16 17:22:45 bcik volumio[14927]: verbose: New 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 16 17:22:45 bcik volumio[14927]: info: Received Get System Info Oct 16 17:22:45 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 17:22:45 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 17:22:45 bcik volumio[14927]: info: Discovery: Getting this device information Oct 16 17:22:45 bcik volumio[14927]: info: CoreCommandRouter::volumioGetState Oct 16 17:22:45 bcik volumio[14927]: info: CorePlayQueue::getTrack 0 Oct 16 17:22:45 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 17:22:45 bcik volumio5-onboarding[15165]: time=2026-10-16T17:22:45.337+02:00 level=INFO msg="system info for 7d49fb3f7a1eba2a5cb01ee26de5f650" deviceName=Bącik deviceVariant=volumio deviceModel= softwareVersion=4.119 Oct 16 17:22:45 bcik go-librespot[15109]: time="2026-10-16T17:22:45+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 16 17:22:45 bcik volumio5-onboarding[15165]: time=2026-10-16T17:22:45.344+02:00 level=INFO msg="bootstrapping state" hasInternet=true Oct 16 17:22:45 bcik volumio[14927]: info: Received Get System Info Oct 16 17:22:45 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 17:22:45 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 17:22:45 bcik volumio[14927]: info: Discovery: Getting this device information Oct 16 17:22:45 bcik volumio[14927]: info: CoreCommandRouter::volumioGetState Oct 16 17:22:45 bcik volumio[14927]: info: CorePlayQueue::getTrack 0 Oct 16 17:22:45 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 17:22:45 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:22:45 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:22:47 bcik volumio-remote-updater[9031]: [2026-10-16 17:22:47] [connect] Successful connection Oct 16 17:22:47 bcik volumio-remote-updater[9031]: [2026-10-16 17:22:47] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1792164167 101 Oct 16 17:22:47 bcik volumio[14927]: 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 16 17:22:48 bcik volumio[14927]: info: go-librespot daemon successfully initialized Oct 16 17:22:48 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 90. Oct 16 17:22:48 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:22:48 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:22:48 bcik go-librespot[15174]: go-librespot daemon starting... Oct 16 17:22:48 bcik go-librespot[15175]: time="2026-10-16T17:22:48+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:22:48 bcik go-librespot[15175]: time="2026-10-16T17:22:48+02:00" level=debug msg="app state loaded" Oct 16 17:22:48 bcik go-librespot[15175]: time="2026-10-16T17:22:48+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:22:48 bcik go-librespot[15175]: time="2026-10-16T17:22:48+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Oct 16 17:22:48 bcik go-librespot[15175]: time="2026-10-16T17:22:48+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 16 17:22:48 bcik go-librespot[15175]: time="2026-10-16T17:22:48+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 16 17:22:48 bcik go-librespot[15175]: time="2026-10-16T17:22:48+02:00" level=info msg="zeroconf server listening on port 37673" Oct 16 17:22:48 bcik go-librespot[15175]: time="2026-10-16T17:22:48+02:00" level=debug msg="obtained new client token: AAHOrDjSJd1ELV5SdbX7M1zAtILUXQbSLpYETx2U0NhnABcPY1kJwG32wyKsr17dUuSK2b7OumAXCs4pjWaOghYaX7wtfsZ5MPIpS1YoPsDMTYfTSSw2XhfLkP4MeOYY8VE6UyPGCQ6SIKOB0ZZ/f9vP7LjHhLrJaN+tiW3pp8MjMK2hHuAyeG5k6IUHowLKJnYE70DSC8MOMCkI7yWDOu1mXekde85ytFu3mdCm7diFluNne/xCcbo=" Oct 16 17:22:48 bcik go-librespot[15175]: time="2026-10-16T17:22:48+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:22:48 bcik go-librespot[15175]: time="2026-10-16T17:22:48+02:00" level=debug msg="completed keyexchange" Oct 16 17:22:48 bcik go-librespot[15175]: time="2026-10-16T17:22:48+02:00" level=debug msg="completed challenge" Oct 16 17:22:48 bcik go-librespot[15175]: time="2026-10-16T17:22:48+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:22:49 bcik go-librespot[15175]: time="2026-10-16T17:22:49+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 16 17:22:49 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:22:49 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:22:50 bcik volumio[14927]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Oct 16 17:22:51 bcik volumio[14927]: info: Initializing connection to go-librespot Websocket Oct 16 17:22:51 bcik volumio[14927]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:22:52 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 91. Oct 16 17:22:52 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:22:52 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:22:52 bcik go-librespot[15184]: go-librespot daemon starting... Oct 16 17:22:52 bcik go-librespot[15185]: time="2026-10-16T17:22:52+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:22:52 bcik go-librespot[15185]: time="2026-10-16T17:22:52+02:00" level=debug msg="app state loaded" Oct 16 17:22:52 bcik go-librespot[15185]: time="2026-10-16T17:22:52+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:22:52 bcik go-librespot[15185]: time="2026-10-16T17:22:52+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Oct 16 17:22:52 bcik go-librespot[15185]: time="2026-10-16T17:22:52+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 16 17:22:52 bcik go-librespot[15185]: time="2026-10-16T17:22:52+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 16 17:22:52 bcik go-librespot[15185]: time="2026-10-16T17:22:52+02:00" level=info msg="zeroconf server listening on port 37455" Oct 16 17:22:52 bcik go-librespot[15185]: time="2026-10-16T17:22:52+02:00" level=debug msg="obtained new client token: AAHk0ytq2LU7Q7hx2za3xTjzSuC0/gAAfHccCSK9nASC2tOAcTuDR95lRKxevr5L2J+UQyNkbTXbh1/0rolLs5k4rJX0N55Y/2YlP97y6Q7twcYbTR1jTYxaDnW9e3F2Kc7rhvo/xlii0wWmgANAsonGZ5axBmcyVLBypgTrANmzlOLBgNvA5nVKQ0poZ+E6vlcp+tKWjY8fjZDQyC1zs4d8AXtgXdPHsg5gKAbBQsQpf3OkQU1mqQU=" Oct 16 17:22:52 bcik go-librespot[15185]: time="2026-10-16T17:22:52+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:22:52 bcik go-librespot[15185]: time="2026-10-16T17:22:52+02:00" level=debug msg="completed keyexchange" Oct 16 17:22:52 bcik go-librespot[15185]: time="2026-10-16T17:22:52+02:00" level=debug msg="completed challenge" Oct 16 17:22:52 bcik go-librespot[15185]: time="2026-10-16T17:22:52+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:22:52 bcik go-librespot[15185]: time="2026-10-16T17:22:52+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 16 17:22:52 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:22:52 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:22:53 bcik sudo[15209]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 16 17:22:53 bcik sudo[15209]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:22:53 bcik sudo[15209]: pam_unix(sudo:session): session closed for user root Oct 16 17:22:53 bcik sudo[15211]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 16 17:22:53 bcik sudo[15211]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:22:53 bcik sudo[15211]: pam_unix(sudo:session): session closed for user root Oct 16 17:22:53 bcik sudo[15214]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Oct 16 17:22:53 bcik sudo[15214]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:22:53 bcik sudo[15214]: pam_unix(sudo:session): session closed for user root Oct 16 17:22:53 bcik volumio[14927]: info: Upmpdcli Daemon Started Oct 16 17:22:53 bcik volumio[14927]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Oct 16 17:22:53 bcik volumio[14927]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Oct 16 17:22:53 bcik volumio[14927]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Oct 16 17:22:53 bcik volumio[14927]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Oct 16 17:22:53 bcik volumio[14927]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Oct 16 17:22:53 bcik volumio[14927]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Oct 16 17:22:53 bcik volumio[14927]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Oct 16 17:22:53 bcik volumio[14927]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Oct 16 17:22:53 bcik volumio[14927]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Oct 16 17:22:53 bcik volumio[14927]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Oct 16 17:22:53 bcik volumio[14927]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Oct 16 17:22:53 bcik volumio[14927]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Oct 16 17:22:53 bcik volumio[14927]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Oct 16 17:22:53 bcik volumio[14927]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Oct 16 17:22:53 bcik volumio[14927]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Oct 16 17:22:53 bcik volumio[14927]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Oct 16 17:22:53 bcik volumio[14927]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Oct 16 17:22:53 bcik volumio[14927]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Oct 16 17:22:53 bcik volumio[14927]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Oct 16 17:22:53 bcik volumio[14927]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Oct 16 17:22:53 bcik volumio[14927]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Oct 16 17:22:53 bcik volumio[14927]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Oct 16 17:22:53 bcik volumio[14927]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Oct 16 17:22:53 bcik volumio[14927]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Oct 16 17:22:53 bcik volumio[14927]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Oct 16 17:22:53 bcik volumio[14927]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Oct 16 17:22:53 bcik volumio[14927]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Oct 16 17:22:53 bcik volumio[14927]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Oct 16 17:22:53 bcik volumio[14927]: info: Adding plugin bluetooth to MyMusic Plugins Oct 16 17:22:53 bcik volumio[14927]: info: Adding plugin multiroom to MyMusic Plugins Oct 16 17:22:53 bcik volumio[14927]: info: Adding plugin metavolumio to MyMusic Plugins Oct 16 17:22:53 bcik volumio[14927]: info: Adding plugin cd_controller to MyMusic Plugins Oct 16 17:22:53 bcik volumio[14927]: info: Adding plugin qobuzconnect to MyMusic Plugins Oct 16 17:22:53 bcik volumio[14927]: info: Adding plugin smart_inputs to MyMusic Plugins Oct 16 17:22:53 bcik volumio[14927]: info: Adding plugin tidalconnect to MyMusic Plugins Oct 16 17:22:53 bcik volumio[14927]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Oct 16 17:22:54 bcik volumio[14927]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Oct 16 17:22:54 bcik volumio[14927]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Oct 16 17:22:54 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:22:54 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:22:54 bcik volumio[14927]: info: Starting MyVolumio Remote Streaming Endpoints Oct 16 17:22:54 bcik volumio[14927]: info: MyVolumio login type: Token Oct 16 17:22:54 bcik volumio[14927]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Oct 16 17:22:54 bcik volumio[14927]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Oct 16 17:22:54 bcik volumio[14927]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Oct 16 17:22:54 bcik volumio[14927]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Oct 16 17:22:54 bcik volumio[14927]: info: Streaming services startup Oct 16 17:22:54 bcik volumio[14927]: info: Starting Streaming Daemon Oct 16 17:22:54 bcik sudo[15218]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 16 17:22:54 bcik sudo[15218]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:22:54 bcik volumio[14927]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Oct 16 17:22:54 bcik volumio[14927]: info: Initializing connection to go-librespot Websocket Oct 16 17:22:54 bcik sudo[15218]: pam_unix(sudo:session): session closed for user root Oct 16 17:22:54 bcik volumio[14927]: error: Cannot start Volumio Streaming Daemon Oct 16 17:22:54 bcik volumio[14927]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 16 17:22:54 bcik volumio[14927]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 16 17:22:54 bcik volumio[14927]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:22:54 bcik volumio[14927]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Oct 16 17:22:55 bcik volumio[14927]: info: MyVolumio token set successfully Oct 16 17:22:55 bcik volumio[14927]: info: MYVOLUMIO: Adding device Oct 16 17:22:55 bcik volumio[14927]: info: MYVOLUMIO: Evaluating Server Oct 16 17:22:55 bcik volumio[14927]: info: MyVolumio status changed Oct 16 17:22:55 bcik volumio[14927]: info: Streaming services startup Oct 16 17:22:55 bcik volumio[14927]: info: Starting Streaming Daemon Oct 16 17:22:55 bcik volumio[14927]: info: Removing browser output: myVolumio user plan is not superstar Oct 16 17:22:55 bcik volumio[14927]: info: Removing audio output: Oct 16 17:22:55 bcik volumio[14927]: info: Stoppping Tunnel 1 Oct 16 17:22:55 bcik sudo[15246]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 16 17:22:55 bcik sudo[15246]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:22:55 bcik sudo[15249]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Oct 16 17:22:55 bcik sudo[15249]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:22:55 bcik sudo[15246]: pam_unix(sudo:session): session closed for user root Oct 16 17:22:55 bcik volumio[14927]: error: Cannot start Volumio Streaming Daemon Oct 16 17:22:55 bcik volumio[14927]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 16 17:22:55 bcik volumio[14927]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 16 17:22:55 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 16 17:22:55 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 16 17:22:55 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 16 17:22:55 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 16 17:22:55 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 16 17:22:55 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 16 17:22:55 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 16 17:22:55 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 16 17:22:55 bcik sudo[15249]: pam_unix(sudo:session): session closed for user root Oct 16 17:22:55 bcik volumio[14927]: info: Remote SSH Stopped Oct 16 17:22:55 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 92. Oct 16 17:22:55 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:22:55 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:22:55 bcik go-librespot[15251]: go-librespot daemon starting... Oct 16 17:22:55 bcik go-librespot[15252]: time="2026-10-16T17:22:55+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:22:55 bcik go-librespot[15252]: time="2026-10-16T17:22:55+02:00" level=debug msg="app state loaded" Oct 16 17:22:55 bcik go-librespot[15252]: time="2026-10-16T17:22:55+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:22:55 bcik volumio[14927]: info: Setting Geolocation for MyVolumio to eu6 Oct 16 17:22:55 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:22:55 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:22:55 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:22:55 bcik go-librespot[15252]: time="2026-10-16T17:22:55+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 16 17:22:55 bcik go-librespot[15252]: time="2026-10-16T17:22:55+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 16 17:22:55 bcik go-librespot[15252]: time="2026-10-16T17:22:55+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 16 17:22:55 bcik go-librespot[15252]: time="2026-10-16T17:22:55+02:00" level=info msg="zeroconf server listening on port 40835" Oct 16 17:22:56 bcik go-librespot[15252]: time="2026-10-16T17:22:56+02:00" level=debug msg="obtained new client token: AAGgs2V5+8sRs9o6NrfmsSGz4YIXDBSGRa3jGSEg5T749TQBOmMcehWqp/ujva1OSVRRzDj/Jp5Q1Q4Qkvpv+N2u+D8px+BmqMPAsjRPK/nwYFKiHGKjP2ZbZ+wNP2LxyfaOx+4HYibNvC63qPkQXFV+OVUYQJhd0ZP3Nxf7nKgt83ivgknQ5IWNwPefIfMa2mWXooHq59Ig/gPPFr882jrcyeZlxBLwF96nNT5GCxvPCcN6cd2R" Oct 16 17:22:56 bcik go-librespot[15252]: time="2026-10-16T17:22:56+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:22:56 bcik go-librespot[15252]: time="2026-10-16T17:22:56+02:00" level=debug msg="completed keyexchange" Oct 16 17:22:56 bcik go-librespot[15252]: time="2026-10-16T17:22:56+02:00" level=debug msg="completed challenge" Oct 16 17:22:56 bcik go-librespot[15252]: time="2026-10-16T17:22:56+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:22:56 bcik go-librespot[15252]: time="2026-10-16T17:22:56+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 16 17:22:56 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:22:56 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:22:56 bcik volumio[14927]: info: Updating MyVolumio device info Oct 16 17:22:56 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:22:56 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:22:56 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:22:57 bcik volumio[14927]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Oct 16 17:22:57 bcik volumio[14927]: info: Initializing connection to go-librespot Websocket Oct 16 17:22:57 bcik volumio[14927]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:22:57 bcik volumio[14927]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Oct 16 17:22:59 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 93. Oct 16 17:22:59 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:22:59 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:22:59 bcik go-librespot[15262]: go-librespot daemon starting... Oct 16 17:22:59 bcik go-librespot[15263]: time="2026-10-16T17:22:59+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:22:59 bcik go-librespot[15263]: time="2026-10-16T17:22:59+02:00" level=debug msg="app state loaded" Oct 16 17:22:59 bcik go-librespot[15263]: time="2026-10-16T17:22:59+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:22:59 bcik go-librespot[15263]: time="2026-10-16T17:22:59+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 16 17:22:59 bcik go-librespot[15263]: time="2026-10-16T17:22:59+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 16 17:22:59 bcik go-librespot[15263]: time="2026-10-16T17:22:59+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 16 17:22:59 bcik go-librespot[15263]: time="2026-10-16T17:22:59+02:00" level=info msg="zeroconf server listening on port 33469" Oct 16 17:22:59 bcik go-librespot[15263]: time="2026-10-16T17:22:59+02:00" level=debug msg="obtained new client token: AAG8mxJ3OOLcgayTBhDurYxs3EhJlYERCtcFJVr46W6Xx8HROcIf1+EefubQgOQCHFcqd4wAn+hULu4wYg6PS2x45xD4kULBEYO22OpFJZGIr5c5KiNesE0pkWDAuKIFyg73geb5A5TGp+rFa1WVrIQawNgE2nxUbQtMgGXy9XibT87ZM0BDtgYSY/kOPxDU14ACfXxyZLButF+PjCpa720HliZZ9Oxd63Iq8RnNyI3YPpe5qTBhDsc=" Oct 16 17:22:59 bcik go-librespot[15263]: time="2026-10-16T17:22:59+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:22:59 bcik go-librespot[15263]: time="2026-10-16T17:22:59+02:00" level=debug msg="completed keyexchange" Oct 16 17:22:59 bcik go-librespot[15263]: time="2026-10-16T17:22:59+02:00" level=debug msg="completed challenge" Oct 16 17:22:59 bcik go-librespot[15263]: time="2026-10-16T17:22:59+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:22:59 bcik go-librespot[15263]: time="2026-10-16T17:22:59+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 16 17:22:59 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:22:59 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:23:00 bcik volumio[14927]: info: Initializing connection to go-librespot Websocket Oct 16 17:23:00 bcik volumio[14927]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:23:01 bcik volumio[14927]: info: MYVOLUMIO: Adding device Oct 16 17:23:01 bcik volumio[14927]: info: MYVOLUMIO: Evaluating Server Oct 16 17:23:01 bcik volumio[14927]: info: Setting Geolocation for MyVolumio to eu6 Oct 16 17:23:01 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:01 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:01 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:01 bcik volumio[14927]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Oct 16 17:23:02 bcik volumio[14927]: info: Updating MyVolumio device info Oct 16 17:23:02 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:02 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:02 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:02 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 94. Oct 16 17:23:02 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:02 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:02 bcik go-librespot[15290]: go-librespot daemon starting... Oct 16 17:23:02 bcik go-librespot[15291]: time="2026-10-16T17:23:02+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:23:02 bcik go-librespot[15291]: time="2026-10-16T17:23:02+02:00" level=debug msg="app state loaded" Oct 16 17:23:02 bcik go-librespot[15291]: time="2026-10-16T17:23:02+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:23:02 bcik volumio[14927]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Oct 16 17:23:02 bcik go-librespot[15291]: time="2026-10-16T17:23:02+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 16 17:23:02 bcik go-librespot[15291]: time="2026-10-16T17:23:02+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 16 17:23:02 bcik go-librespot[15291]: time="2026-10-16T17:23:02+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 16 17:23:02 bcik go-librespot[15291]: time="2026-10-16T17:23:02+02:00" level=info msg="zeroconf server listening on port 37927" Oct 16 17:23:02 bcik go-librespot[15291]: time="2026-10-16T17:23:02+02:00" level=debug msg="obtained new client token: AAHunVCsd3TaJuRBDllwPd04y1gwjsH8l2NqE84p/3vtQZOvOSRRXyKbiz9sJNnNygkpSXOuF3B44JWdRks844WTeo84bjJrtdWfgkc8TIhvVuhTXiTghVWffwzl8Lrs0LaT1v/FePhPwPLIJo0Ffuqr1Je79jwxF7IqfAgmNCzyCIrN51GfmodQVdqifQHYfgS4zlXQJ28d921gd3mE0QhutW8SRnMzMnp1EnrQCMbU806ty6GjILM=" Oct 16 17:23:03 bcik go-librespot[15291]: time="2026-10-16T17:23:03+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:23:03 bcik go-librespot[15291]: time="2026-10-16T17:23:03+02:00" level=debug msg="completed keyexchange" Oct 16 17:23:03 bcik go-librespot[15291]: time="2026-10-16T17:23:03+02:00" level=debug msg="completed challenge" Oct 16 17:23:03 bcik go-librespot[15291]: time="2026-10-16T17:23:03+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:23:03 bcik go-librespot[15291]: time="2026-10-16T17:23:03+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 16 17:23:03 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:23:03 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:23:03 bcik volumio[14927]: info: Initializing connection to go-librespot Websocket Oct 16 17:23:03 bcik volumio[14927]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:23:06 bcik volumio[14927]: info: Initializing connection to go-librespot Websocket Oct 16 17:23:06 bcik volumio[14927]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:23:06 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 95. Oct 16 17:23:06 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:06 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:06 bcik go-librespot[15314]: go-librespot daemon starting... Oct 16 17:23:06 bcik go-librespot[15315]: time="2026-10-16T17:23:06+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:23:06 bcik go-librespot[15315]: time="2026-10-16T17:23:06+02:00" level=debug msg="app state loaded" Oct 16 17:23:06 bcik go-librespot[15315]: time="2026-10-16T17:23:06+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:23:06 bcik go-librespot[15315]: time="2026-10-16T17:23:06+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 16 17:23:06 bcik go-librespot[15315]: time="2026-10-16T17:23:06+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 16 17:23:06 bcik go-librespot[15315]: time="2026-10-16T17:23:06+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 16 17:23:06 bcik go-librespot[15315]: time="2026-10-16T17:23:06+02:00" level=info msg="zeroconf server listening on port 39565" Oct 16 17:23:06 bcik go-librespot[15315]: time="2026-10-16T17:23:06+02:00" level=debug msg="obtained new client token: AAENl2tX1lK6ANkvzP/JKqBt7/k3WNXjwp7NVtJGxCO/sdFYv+iEj2Z4pvJp4oIP9gHQXh/gfzEoa80tKhaFkB3luxraERgslDxNn6d9NW89E2iz8n4+M/ZJts6SBDmcJNHaCOC0OcV3cWkMVbx98Uwj1PWgODypFfapS6Y+JHKDxtmkA+krmYx/I4yL9eGt9EPWgrSlH6djjp6KVRjfMeqPSPTvcqCQNoHRuvrf3OHknqp98ty9PuM=" Oct 16 17:23:06 bcik go-librespot[15315]: time="2026-10-16T17:23:06+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:23:06 bcik go-librespot[15315]: time="2026-10-16T17:23:06+02:00" level=debug msg="completed keyexchange" Oct 16 17:23:06 bcik go-librespot[15315]: time="2026-10-16T17:23:06+02:00" level=debug msg="completed challenge" Oct 16 17:23:06 bcik go-librespot[15315]: time="2026-10-16T17:23:06+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:23:06 bcik go-librespot[15315]: time="2026-10-16T17:23:06+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 16 17:23:06 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:23:06 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:23:09 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 16 17:23:09 bcik volumio[14927]: 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 16 17:23:09 bcik volumio[14927]: info: CoreCommandRouter::volumioGetState Oct 16 17:23:09 bcik volumio[14927]: info: CorePlayQueue::getTrack 0 Oct 16 17:23:09 bcik volumio[14927]: info: Initializing connection to go-librespot Websocket Oct 16 17:23:09 bcik volumio[14927]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:23:10 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 96. Oct 16 17:23:10 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:10 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:10 bcik go-librespot[15324]: go-librespot daemon starting... Oct 16 17:23:10 bcik go-librespot[15325]: time="2026-10-16T17:23:10+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:23:10 bcik go-librespot[15325]: time="2026-10-16T17:23:10+02:00" level=debug msg="app state loaded" Oct 16 17:23:10 bcik go-librespot[15325]: time="2026-10-16T17:23:10+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:23:10 bcik go-librespot[15325]: time="2026-10-16T17:23:10+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 16 17:23:10 bcik go-librespot[15325]: time="2026-10-16T17:23:10+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 16 17:23:10 bcik go-librespot[15325]: time="2026-10-16T17:23:10+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 16 17:23:10 bcik go-librespot[15325]: time="2026-10-16T17:23:10+02:00" level=info msg="zeroconf server listening on port 35415" Oct 16 17:23:10 bcik go-librespot[15325]: time="2026-10-16T17:23:10+02:00" level=debug msg="obtained new client token: AAGvcr+cZ00wOVk68lFGZfdscsHysaqUSapoXnF80vzOIzc6XB/9Wx0J8sihklIFdSftc3uvRkFQAF+JJDzOwnAsDIob6GP1YChhdaL2sDexRJfIKIhL2EJTG8FnsKktzwmg2vV1SVqiNGLYsERmKet3FdOPOZjz89lM8Al2gYXwjHn2ACSSue3Kq8pMvCGxkI6FjgxfqnZIhNv6sxhQCXyLfAPxYmxMmdngWOuAx/oSxvUFasb2" Oct 16 17:23:10 bcik go-librespot[15325]: time="2026-10-16T17:23:10+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:23:10 bcik go-librespot[15325]: time="2026-10-16T17:23:10+02:00" level=debug msg="completed keyexchange" Oct 16 17:23:10 bcik go-librespot[15325]: time="2026-10-16T17:23:10+02:00" level=debug msg="completed challenge" Oct 16 17:23:10 bcik go-librespot[15325]: time="2026-10-16T17:23:10+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:23:10 bcik go-librespot[15325]: time="2026-10-16T17:23:10+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 16 17:23:10 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:23:10 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:23:12 bcik volumio[14927]: info: Initializing connection to go-librespot Websocket Oct 16 17:23:12 bcik volumio[14927]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:23:13 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 97. Oct 16 17:23:13 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:13 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:13 bcik go-librespot[15348]: go-librespot daemon starting... Oct 16 17:23:13 bcik go-librespot[15349]: time="2026-10-16T17:23:13+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:23:13 bcik go-librespot[15349]: time="2026-10-16T17:23:13+02:00" level=debug msg="app state loaded" Oct 16 17:23:13 bcik go-librespot[15349]: time="2026-10-16T17:23:13+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:23:13 bcik go-librespot[15349]: time="2026-10-16T17:23:13+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 16 17:23:13 bcik go-librespot[15349]: time="2026-10-16T17:23:13+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 16 17:23:13 bcik go-librespot[15349]: time="2026-10-16T17:23:13+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 16 17:23:13 bcik go-librespot[15349]: time="2026-10-16T17:23:13+02:00" level=info msg="zeroconf server listening on port 43309" Oct 16 17:23:13 bcik go-librespot[15349]: time="2026-10-16T17:23:13+02:00" level=debug msg="obtained new client token: AAE7jJshkaV8lS/azwxJHBUDPNyu8xeooVq8WtIh39Uz5DEdrV7vBU+/W+j4J5uHPJBh3jmRa94HKnwyMGuGsDbz4TntGocjfnxdAb3cJ0U99V/GQjnxeCMkPyQGN77p/7XXHKLFCGqfMr3Tj8C2uDIQ3rm+KmNiZXTFeHnmg2I7CE6yP4D62LmRmOzxUP27juSP1mq3dqTz1AKKLm3rfDq6y9u6Dv2hXJ4krVSElwFh7NznTAEODOE=" Oct 16 17:23:14 bcik go-librespot[15349]: time="2026-10-16T17:23:14+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:23:14 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:14 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:14 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Oct 16 17:23:14 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Oct 16 17:23:14 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Oct 16 17:23:14 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Oct 16 17:23:14 bcik volumio[14927]: info: CoreCommandRouter::volumioGetBrowseSources Oct 16 17:23:14 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 16 17:23:14 bcik go-librespot[15349]: time="2026-10-16T17:23:14+02:00" level=debug msg="completed keyexchange" Oct 16 17:23:14 bcik go-librespot[15349]: time="2026-10-16T17:23:14+02:00" level=debug msg="completed challenge" Oct 16 17:23:14 bcik go-librespot[15349]: time="2026-10-16T17:23:14+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:23:14 bcik go-librespot[15349]: time="2026-10-16T17:23:14+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 16 17:23:14 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:23:14 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:23:14 bcik volumio[14927]: error: MyVolumio Plugin failed to authenticate in a timely fashion Oct 16 17:23:14 bcik volumio[14927]: info: Completed starting MyVolumio Plugin Oct 16 17:23:14 bcik volumio[14927]: [Metrics] CommandRouter: 31s 17.23ms Oct 16 17:23:14 bcik volumio[14927]: info: CoreCommandRouter::volumiosetStartupVolume Oct 16 17:23:14 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:14 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:14 bcik volumio[14927]: info: CoreCommandRouter::Close All Modals sent Oct 16 17:23:14 bcik volumio[14927]: info: CoreCommandRouter::Close All Modals sent Oct 16 17:23:14 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 16 17:23:14 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:14 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 16 17:23:14 bcik volumio-remote-updater[9031]: Test mode disabled Oct 16 17:23:14 bcik volumio-remote-updater[9031]: Alpha mode disabled Oct 16 17:23:14 bcik volumio-remote-updater[9031]: Alpha legacy test mode disabled Oct 16 17:23:14 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Oct 16 17:23:14 bcik volumio[14927]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Oct 16 17:23:14 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Oct 16 17:23:14 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 16 17:23:14 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 16 17:23:14 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 16 17:23:15 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Oct 16 17:23:15 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 16 17:23:15 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Oct 16 17:23:15 bcik volumio[14927]: info: Initializing connection to go-librespot Websocket Oct 16 17:23:15 bcik volumio[14927]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:23:15 bcik volumio5-onboarding[15165]: time=2026-10-16T17:23:15.288+02:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=tidal error="could not open plugin config file for \"tidal\": open /data/configuration/music_service/tidal/config.json: no such file or directory" Oct 16 17:23:15 bcik volumio5-onboarding[15165]: time=2026-10-16T17:23:15.289+02:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=qobuz error="could not open plugin config file for \"qobuz\": open /data/configuration/music_service/qobuz/config.json: no such file or directory" Oct 16 17:23:15 bcik volumio5-onboarding[15165]: time=2026-10-16T17:23:15.289+02:00 level=WARN msg="could not read username/password data for music provider" component=volumio provider=hi_res_audio error="could not open plugin config file for \"hi_res_audio\": open /data/configuration/music_service/hi_res_audio/config.json: no such file or directory" Oct 16 17:23:15 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 16 17:23:15 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 16 17:23:15 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 16 17:23:15 bcik volumio5-onboarding[15165]: failed to bootstrap state: failed to get available plugins: could not get available plugins: context deadline exceeded Oct 16 17:23:15 bcik systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:23:15 bcik systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Oct 16 17:23:15 bcik systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 364. Oct 16 17:23:15 bcik systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Oct 16 17:23:15 bcik systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Oct 16 17:23:15 bcik volumio5-onboarding[15366]: time=2026-10-16T17:23:15.585+02:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Oct 16 17:23:15 bcik volumio[14927]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 4 Oct 16 17:23:15 bcik volumio[14927]: info: Received Get System Info Oct 16 17:23:15 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 17:23:15 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 17:23:15 bcik volumio[14927]: info: Discovery: Getting this device information Oct 16 17:23:15 bcik volumio[14927]: info: CoreCommandRouter::volumioGetState Oct 16 17:23:15 bcik volumio[14927]: info: CorePlayQueue::getTrack 0 Oct 16 17:23:15 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 17:23:15 bcik volumio5-onboarding[15366]: time=2026-10-16T17:23:15.597+02:00 level=INFO msg="system info for 7d49fb3f7a1eba2a5cb01ee26de5f650" deviceName=Bącik deviceVariant=volumio deviceModel= softwareVersion=4.119 Oct 16 17:23:15 bcik volumio[14927]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 4 Oct 16 17:23:15 bcik volumio5-onboarding[15366]: time=2026-10-16T17:23:15.603+02:00 level=INFO msg="bootstrapping state" hasInternet=true Oct 16 17:23:15 bcik volumio[14927]: info: Received Get System Info Oct 16 17:23:15 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 17:23:15 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 17:23:15 bcik volumio[14927]: info: Discovery: Getting this device information Oct 16 17:23:15 bcik volumio[14927]: info: CoreCommandRouter::volumioGetState Oct 16 17:23:15 bcik volumio[14927]: info: CorePlayQueue::getTrack 0 Oct 16 17:23:15 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 17:23:15 bcik volumio-remote-updater[9031]: Test mode disabled Oct 16 17:23:15 bcik volumio-remote-updater[9031]: Alpha mode disabled Oct 16 17:23:15 bcik volumio-remote-updater[9031]: Alpha legacy test mode disabled Oct 16 17:23:15 bcik volumio[14927]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Oct 16 17:23:15 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Oct 16 17:23:15 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 16 17:23:15 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 16 17:23:15 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 16 17:23:15 bcik volumio5-onboarding[15366]: time=2026-10-16T17:23:15.952+02:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=tidal error="could not open plugin config file for \"tidal\": open /data/configuration/music_service/tidal/config.json: no such file or directory" Oct 16 17:23:15 bcik volumio5-onboarding[15366]: time=2026-10-16T17:23:15.953+02:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=qobuz error="could not open plugin config file for \"qobuz\": open /data/configuration/music_service/qobuz/config.json: no such file or directory" Oct 16 17:23:15 bcik volumio5-onboarding[15366]: time=2026-10-16T17:23:15.953+02:00 level=WARN msg="could not read username/password data for music provider" component=volumio provider=hi_res_audio error="could not open plugin config file for \"hi_res_audio\": open /data/configuration/music_service/hi_res_audio/config.json: no such file or directory" Oct 16 17:23:15 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 16 17:23:15 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 16 17:23:15 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 16 17:23:16 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 16 17:23:16 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 16 17:23:17 bcik volumio5-onboarding[15366]: time=2026-10-16T17:23:17.033+02:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=9ixt1umkBgVYLY7gQzekBTAkTI72 tokenExpiry=2026-10-16T18:23:17.033+02:00 Oct 16 17:23:17 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 98. Oct 16 17:23:17 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:17 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:17 bcik go-librespot[15378]: go-librespot daemon starting... Oct 16 17:23:17 bcik go-librespot[15379]: time="2026-10-16T17:23:17+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:23:17 bcik go-librespot[15379]: time="2026-10-16T17:23:17+02:00" level=debug msg="app state loaded" Oct 16 17:23:17 bcik go-librespot[15379]: time="2026-10-16T17:23:17+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:23:17 bcik go-librespot[15379]: time="2026-10-16T17:23:17+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 16 17:23:17 bcik go-librespot[15379]: time="2026-10-16T17:23:17+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 16 17:23:17 bcik go-librespot[15379]: time="2026-10-16T17:23:17+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 16 17:23:17 bcik go-librespot[15379]: time="2026-10-16T17:23:17+02:00" level=info msg="zeroconf server listening on port 38091" Oct 16 17:23:17 bcik go-librespot[15379]: time="2026-10-16T17:23:17+02:00" level=debug msg="obtained new client token: AAGrFIYDOKMW84pu8ylNTB/3WGzrwmRMPuVe+370l5tosOQJvA9bx5L+UK/+skBc3XAnXPTlXxS82qFm1pbkrT/mOCNfrVc3FOh+Xaml38Ah96iIfAZZyeiAaVcOQGhQ79p6zxlW68tTNYaRNkGANBlGx4rHSxlzXWULh1bZSxnegsAB1sI2GYQhOX+HDwRAE2KfSx/bep0oZu6bZxxJJazru329ngDVXcq84DaIUsyTuEimAqdI8HA=" Oct 16 17:23:17 bcik go-librespot[15379]: time="2026-10-16T17:23:17+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:23:17 bcik go-librespot[15379]: time="2026-10-16T17:23:17+02:00" level=debug msg="completed keyexchange" Oct 16 17:23:17 bcik go-librespot[15379]: time="2026-10-16T17:23:17+02:00" level=debug msg="completed challenge" Oct 16 17:23:17 bcik go-librespot[15379]: time="2026-10-16T17:23:17+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:23:17 bcik go-librespot[15379]: time="2026-10-16T17:23:17+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 16 17:23:17 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:23:17 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:23:17 bcik volumio[14927]: info: Received Get System Info Oct 16 17:23:17 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 17:23:17 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 17:23:17 bcik volumio[14927]: info: Discovery: Getting this device information Oct 16 17:23:17 bcik volumio[14927]: info: CoreCommandRouter::volumioGetState Oct 16 17:23:17 bcik volumio[14927]: info: CorePlayQueue::getTrack 0 Oct 16 17:23:17 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 17:23:17 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 16 17:23:17 bcik volumio[14927]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 16 17:23:17 bcik volumio5-onboarding[15366]: time=2026-10-16T17:23:17.753+02:00 level=INFO msg="enabling local network discovery" Oct 16 17:23:17 bcik volumio5-onboarding[15366]: time=2026-10-16T17:23:17.759+02:00 level=INFO msg="enabling BLE discovery" Oct 16 17:23:18 bcik volumio[14927]: info: Initializing connection to go-librespot Websocket Oct 16 17:23:18 bcik volumio[14927]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:23:18 bcik volumio5-onboarding[15366]: time=2026-10-16T17:23:18.774+02:00 level=INFO msg="service successfully established" component=discovery/localnet Oct 16 17:23:20 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 99. Oct 16 17:23:20 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:20 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:20 bcik go-librespot[15390]: go-librespot daemon starting... Oct 16 17:23:20 bcik go-librespot[15391]: time="2026-10-16T17:23:20+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:23:20 bcik go-librespot[15391]: time="2026-10-16T17:23:20+02:00" level=debug msg="app state loaded" Oct 16 17:23:20 bcik go-librespot[15391]: time="2026-10-16T17:23:20+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:23:20 bcik go-librespot[15391]: time="2026-10-16T17:23:20+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 16 17:23:20 bcik go-librespot[15391]: time="2026-10-16T17:23:20+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 16 17:23:20 bcik go-librespot[15391]: time="2026-10-16T17:23:20+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 16 17:23:20 bcik go-librespot[15391]: time="2026-10-16T17:23:20+02:00" level=info msg="zeroconf server listening on port 36227" Oct 16 17:23:21 bcik go-librespot[15391]: time="2026-10-16T17:23:21+02:00" level=debug msg="obtained new client token: AAFlomq5LVfShvINsRwwAfXG/QdfFOlA5FMmy/8lOBp5gAKYahso3geoVTaXxD/tooC3uvd9acc3TLQaxpaPIacZeAD8Ay0C2pm02hWchwVL9R8YYj4tfSbSa2/oC1pwrUZGkrB1SvFtkIVIEIpZXi32NNFW2xJt5pqd57PksdNBemE4qjvJOEgqBUzIgTe/UDMVhVoZeZTD7oQO+bSF2db6N9g1DweyIPbzyOKG6Y/uf2Ayy201" Oct 16 17:23:21 bcik go-librespot[15391]: time="2026-10-16T17:23:21+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:23:21 bcik go-librespot[15391]: time="2026-10-16T17:23:21+02:00" level=debug msg="completed keyexchange" Oct 16 17:23:21 bcik go-librespot[15391]: time="2026-10-16T17:23:21+02:00" level=debug msg="completed challenge" Oct 16 17:23:21 bcik volumio[14927]: info: BOOT COMPLETED Oct 16 17:23:21 bcik volumio[14927]: info: Initializing connection to go-librespot Websocket Oct 16 17:23:21 bcik go-librespot[15391]: time="2026-10-16T17:23:21+02:00" level=debug msg="new websocket client" Oct 16 17:23:21 bcik volumio[14927]: info: Connection to go-librespot Websocket established Oct 16 17:23:21 bcik go-librespot[15391]: time="2026-10-16T17:23:21+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:23:21 bcik go-librespot[15391]: time="2026-10-16T17:23:21+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 16 17:23:21 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:23:21 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:23:21 bcik volumio[14927]: info: Connection to go-librespot Websocket closed Oct 16 17:23:24 bcik volumio[14927]: info: Getting Spotify volume Oct 16 17:23:24 bcik volumio[14927]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 16 17:23:24 bcik volumio[14927]: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:23:24 bcik volumio[14927]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Oct 16 17:23:24 bcik volumio[14927]: errno: -111, Oct 16 17:23:24 bcik volumio[14927]: code: 'ECONNREFUSED', Oct 16 17:23:24 bcik volumio[14927]: syscall: 'connect', Oct 16 17:23:24 bcik volumio[14927]: address: '127.0.0.1', Oct 16 17:23:24 bcik volumio[14927]: port: 9879, Oct 16 17:23:24 bcik volumio[14927]: response: undefined Oct 16 17:23:24 bcik volumio[14927]: } Oct 16 17:23:24 bcik volumio[14927]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 16 17:23:24 bcik sudo[15429]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-16 17:22' Oct 16 17:23:24 bcik sudo[15429]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:24 bcik sudo[15429]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:24 bcik volumio5-onboarding[15366]: time=2026-10-16T17:23:24.481+02:00 level=ERROR msg="failed reading message" error="websocket: close 1006 (abnormal closure): unexpected EOF" Oct 16 17:23:24 bcik volumio-remote-updater[9031]: [2026-10-16 17:23:24] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Oct 16 17:23:24 bcik volumio-remote-updater[9031]: [2026-10-16 17:23:24] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Oct 16 17:23:24 bcik volumio5-onboarding[15366]: time=2026-10-16T17:23:24.482+02:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Oct 16 17:23:24 bcik systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:23:24 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 100. Oct 16 17:23:24 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:24 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:24 bcik go-librespot[15434]: go-librespot daemon starting... Oct 16 17:23:24 bcik systemd[1]: volumio.service: Failed with result 'exit-code'. Oct 16 17:23:24 bcik systemd[1]: volumio.service: Consumed 7.030s CPU time. Oct 16 17:23:24 bcik systemd[1]: Started dynamicswap.service - dynamicswap service. Oct 16 17:23:24 bcik go-librespot[15438]: time="2026-10-16T17:23:24+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:23:24 bcik go-librespot[15438]: time="2026-10-16T17:23:24+02:00" level=debug msg="app state loaded" Oct 16 17:23:24 bcik go-librespot[15438]: time="2026-10-16T17:23:24+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:23:24 bcik systemd[1]: dynamicswap.service: Deactivated successfully. Oct 16 17:23:24 bcik go-librespot[15438]: time="2026-10-16T17:23:24+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 16 17:23:24 bcik go-librespot[15438]: time="2026-10-16T17:23:24+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 16 17:23:24 bcik go-librespot[15438]: time="2026-10-16T17:23:24+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 16 17:23:24 bcik go-librespot[15438]: time="2026-10-16T17:23:24+02:00" level=info msg="zeroconf server listening on port 34723" Oct 16 17:23:24 bcik go-librespot[15438]: time="2026-10-16T17:23:24+02:00" level=debug msg="obtained new client token: AAHbFb0dW6v6YaacARXYGCMH1TyOTvFLcmBAn20nwAR2jvnbNEVU8TD12Pw/RKnIFMwc0afzhKRnLRTwlINc2/lMjbvZUCfs5OX+8yOC7BzAjCP3GRTZBFz8Wx+5cbGDQdLFRc9BTdetplV6kPn2uHMlgC7nclWQH8mcsZN97+X7ft1BagV7/z2mWZrsJr4q/hmbNoDLeH2Ndu5IT4DHBhJ8juJUFnzCb5cXxUDQMJzGqa7/Jf1XVRk=" Oct 16 17:23:24 bcik go-librespot[15438]: time="2026-10-16T17:23:24+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:23:24 bcik go-librespot[15438]: time="2026-10-16T17:23:24+02:00" level=debug msg="completed keyexchange" Oct 16 17:23:24 bcik go-librespot[15438]: time="2026-10-16T17:23:24+02:00" level=debug msg="completed challenge" Oct 16 17:23:24 bcik systemd[1]: volumio.service: Scheduled restart job, restart counter is at 27696. Oct 16 17:23:24 bcik systemd[1]: Started dynamicswap.service - dynamicswap service. Oct 16 17:23:24 bcik systemd[1]: Stopped volumio.service - Volumio Backend Module. Oct 16 17:23:24 bcik systemd[1]: volumio.service: Consumed 7.030s CPU time. Oct 16 17:23:24 bcik systemd[1]: Started volumio.service - Volumio Backend Module. Oct 16 17:23:24 bcik systemd[1]: dynamicswap.service: Deactivated successfully. Oct 16 17:23:24 bcik go-librespot[15438]: time="2026-10-16T17:23:24+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:23:24 bcik go-librespot[15438]: time="2026-10-16T17:23:24+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 16 17:23:24 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:23:24 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:23:25 bcik volumio[15453]: info: ------------------------------------------- Oct 16 17:23:25 bcik volumio[15453]: info: ----- Volumio3 ---- Oct 16 17:23:25 bcik volumio[15453]: info: ------------------------------------------- Oct 16 17:23:25 bcik volumio[15453]: info: ----- System startup ---- Oct 16 17:23:25 bcik volumio[15453]: info: ------------------------------------------- Oct 16 17:23:25 bcik volumio[15453]: info: MYVOLUMIO Environment detected Oct 16 17:23:25 bcik volumio[15453]: info: Plugin folders cleanup Oct 16 17:23:25 bcik volumio[15453]: info: Scanning into folder /volumio/app/plugins/ Oct 16 17:23:25 bcik volumio[15453]: info: Scanning category audio_interface Oct 16 17:23:25 bcik volumio[15453]: info: Scanning category miscellanea Oct 16 17:23:25 bcik volumio[15453]: info: Scanning category music_service Oct 16 17:23:25 bcik volumio[15453]: info: Scanning category plugins.json Oct 16 17:23:25 bcik volumio[15453]: info: Scanning category system_controller Oct 16 17:23:25 bcik volumio[15453]: info: Scanning category user_interface Oct 16 17:23:25 bcik volumio[15453]: info: Scanning into folder /data/plugins/ Oct 16 17:23:25 bcik volumio[15453]: info: Scanning category music_service Oct 16 17:23:25 bcik volumio[15453]: info: Plugin folders cleanup completed Oct 16 17:23:25 bcik volumio[15453]: info: ------------------------------------------- Oct 16 17:23:25 bcik volumio[15453]: info: ----- Core plugins startup ---- Oct 16 17:23:25 bcik volumio[15453]: info: ------------------------------------------- Oct 16 17:23:25 bcik volumio[15453]: info: Loading plugins from folder /volumio/app/plugins/ Oct 16 17:23:25 bcik volumio[15453]: info: Adding plugin upnp to MyMusic Plugins Oct 16 17:23:25 bcik volumio[15453]: info: Adding plugin airplay_emulation to MyMusic Plugins Oct 16 17:23:25 bcik volumio[15453]: info: Adding plugin upnp_browser to MyMusic Plugins Oct 16 17:23:25 bcik volumio[15453]: info: Loading plugins from folder /data/plugins/ Oct 16 17:23:25 bcik volumio[15453]: info: Loading plugin "system"... Oct 16 17:23:25 bcik volumio[15453]: info: Loading plugin "appearance"... Oct 16 17:23:25 bcik volumio[15453]: info: Loading plugin "network"... Oct 16 17:23:25 bcik volumio[15453]: info: Refreshing Cached IP Addresses Oct 16 17:23:25 bcik sudo[15481]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 16 17:23:25 bcik sudo[15481]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:25 bcik sudo[15483]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 16 17:23:25 bcik sudo[15483]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:25 bcik sudo[15481]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:25 bcik sudo[15483]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:25 bcik volumio[15453]: info: Loading plugin "services"... Oct 16 17:23:25 bcik volumio[15453]: info: Loading plugin "volumio5onboarding"... Oct 16 17:23:25 bcik volumio[15453]: info: Loading plugin "alsa_controller"... Oct 16 17:23:25 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 16 17:23:25 bcik volumio[15453]: info: Loading plugin "wizard"... Oct 16 17:23:25 bcik volumio[15453]: info: Loading plugin "networkfs"... Oct 16 17:23:25 bcik volumio[15453]: info: Starting Udev Watcher for removable devices Oct 16 17:23:25 bcik volumio[15453]: info: Ignoring mount for partition: boot Oct 16 17:23:25 bcik volumio[15453]: info: Ignoring mount for partition: volumio Oct 16 17:23:25 bcik volumio[15453]: info: Ignoring mount for partition: volumio_data Oct 16 17:23:25 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 16 17:23:25 bcik volumio[15453]: info: Loading plugin "volumio_command_line_client"... Oct 16 17:23:25 bcik volumio[15453]: info: Loading plugin "upnp"... Oct 16 17:23:25 bcik volumio[15453]: info: [1792164205615] Starting Upmpd Daemon Oct 16 17:23:25 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 16 17:23:25 bcik volumio[15453]: info: Loading plugin "my_music"... Oct 16 17:23:25 bcik volumio[15453]: info: Loading plugin "mpd"... Oct 16 17:23:25 bcik volumio[15453]: info: Loading plugin "upnp_browser"... Oct 16 17:23:25 bcik volumio[15453]: info: Starting UPNP Browser Oct 16 17:23:25 bcik volumio[15453]: info: Loading plugin "alarm-clock"... Oct 16 17:23:25 bcik volumio[15453]: info: Loading plugin "airplay_emulation"... Oct 16 17:23:26 bcik volumio[15453]: info: Starting Shairport Sync Oct 16 17:23:26 bcik volumio[15453]: info: Loading plugin "last_100"... Oct 16 17:23:26 bcik volumio[15453]: info: Loading plugin "webradio"... Oct 16 17:23:26 bcik volumio[15453]: info: Loading plugin "i2s_dacs"... Oct 16 17:23:26 bcik volumio[15453]: info: Loading plugin "volumiodiscovery"... Oct 16 17:23:26 bcik volumio[15453]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 16 17:23:26 bcik volumio[15453]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 16 17:23:26 bcik volumio[15453]: *** WARNING *** For more information see Oct 16 17:23:26 bcik volumio[15453]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 16 17:23:26 bcik volumio[15453]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 16 17:23:26 bcik volumio[15453]: *** WARNING *** For more information see Oct 16 17:23:26 bcik node[15453]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 16 17:23:26 bcik node[15453]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 16 17:23:26 bcik node[15453]: *** WARNING *** For more information see Oct 16 17:23:26 bcik node[15453]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 16 17:23:26 bcik node[15453]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 16 17:23:26 bcik node[15453]: *** WARNING *** For more information see Oct 16 17:23:26 bcik volumio[15453]: info: Applying required configuration parameters for plugin volumiodiscovery Oct 16 17:23:26 bcik volumio[15453]: info: Discovery: Started advertising with name: Bącik Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 16 17:23:26 bcik volumio[15453]: info: Loading plugin "spop"... Oct 16 17:23:26 bcik volumio[15453]: info: Loading plugin "outputs"... Oct 16 17:23:26 bcik volumio[15453]: info: Loading plugin "albumart"... Oct 16 17:23:26 bcik volumio[15453]: info: Plugin example_plugin is not enabled Oct 16 17:23:26 bcik volumio[15453]: info: Loading plugin "inputs"... Oct 16 17:23:26 bcik volumio[15453]: info: Loading plugin "updater_comm"... Oct 16 17:23:26 bcik volumio[15453]: info: Plugin mpdemulation is not enabled Oct 16 17:23:26 bcik volumio[15453]: info: Loading plugin "rest_api"... Oct 16 17:23:26 bcik volumio[15453]: info: Loading plugin "websocket"... Oct 16 17:23:26 bcik volumio[15453]: info: Starting Socket.io Server version 1.7.4 Oct 16 17:23:26 bcik volumio[15453]: info: Loading plugin "radio_browser"... Oct 16 17:23:26 bcik volumio[15513]: Forking 3 albumart workers Oct 16 17:23:26 bcik volumio[15453]: info: Loading i18n strings for locale pl Oct 16 17:23:26 bcik volumio[15453]: Updating browse sources language Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::initPlayerControls Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: Express server listening on port 3000 Oct 16 17:23:26 bcik volumio[15453]: [Metrics] WebUI: 1s 286.53ms Oct 16 17:23:26 bcik volumio[15453]: info: CoreStateMachine::resetVolumioState Oct 16 17:23:26 bcik volumio[15453]: info: CoreStateMachine::getcurrentVolume Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::volumioRetrievevolume Oct 16 17:23:26 bcik volumio[15453]: info: Volumio Network Manager: Network status updated: 1 Oct 16 17:23:26 bcik volumio[15453]: verbose: New 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 16 17:23:26 bcik volumio[15453]: info: VolumeController:: Volume=41 Mute =false Oct 16 17:23:26 bcik volumio[15453]: info: CoreStateMachine::pushState Oct 16 17:23:26 bcik volumio[15453]: info: CorePlayQueue::getTrack 0 Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::volumioPushState Oct 16 17:23:26 bcik volumio[15453]: info: CoreStateMachine::updateTrackBlock Oct 16 17:23:26 bcik volumio[15453]: info: CorePlayQueue::getTrackBlock Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::volumioRetrievevolume Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: Reloading queue from file Oct 16 17:23:26 bcik volumio[15453]: verbose: New 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 16 17:23:26 bcik volumio[15453]: info: CoreStateMachine::setRepeat false single undefined Oct 16 17:23:26 bcik volumio[15453]: info: CoreStateMachine::pushState Oct 16 17:23:26 bcik volumio[15453]: info: CorePlayQueue::getTrack 0 Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::volumioPushState Oct 16 17:23:26 bcik volumio[15453]: info: CoreStateMachine::setRandom false Oct 16 17:23:26 bcik volumio[15453]: info: CoreStateMachine::pushState Oct 16 17:23:26 bcik volumio[15453]: info: CorePlayQueue::getTrack 0 Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::volumioPushState Oct 16 17:23:26 bcik volumio[15453]: info: Setting Device type: Raspberry PI Oct 16 17:23:26 bcik volumio[15453]: info: Completed loading Core Plugins Oct 16 17:23:26 bcik volumio[15453]: info: Preparing to generate the ALSA configuration file Oct 16 17:23:26 bcik volumio[15453]: verbose: New 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 16 17:23:26 bcik volumio[15453]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Oct 16 17:23:26 bcik volumio[15453]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04171 Oct 16 17:23:26 bcik volumio[15453]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Oct 16 17:23:26 bcik volumio[15453]: info: VolumeController:: Volume=41 Mute =false Oct 16 17:23:26 bcik volumio[15453]: info: CoreStateMachine::pushState Oct 16 17:23:26 bcik volumio[15453]: info: CorePlayQueue::getTrack 0 Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::volumioPushState Oct 16 17:23:26 bcik volumio[15453]: verbose: New 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 16 17:23:26 bcik volumio[15453]: verbose: New 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 16 17:23:26 bcik volumio[15453]: info: Asound.conf file unchanged, so no further update is needed Oct 16 17:23:26 bcik volumio[15453]: info: Output device has changed, restarting MPD Oct 16 17:23:26 bcik volumio[15453]: info: Output device has changed, restarting Shairport Sync Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:26 bcik sudo[15567]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 16 17:23:26 bcik sudo[15567]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:26 bcik sudo[15571]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 16 17:23:26 bcik sudo[15571]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:26 bcik volumio[15453]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 16 17:23:26 bcik volumio[15453]: info: ___________ START PLUGINS ___________ Oct 16 17:23:26 bcik sudo[15567]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:26 bcik volumio[15453]: info: ControllerMpd::onStart: Initializing MPD Oct 16 17:23:26 bcik volumio[15453]: info: Creating MPD Configuration file Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 16 17:23:26 bcik volumio[15453]: info: [1792164206533] CoreMusicLibrary::Adding element Serwery Mediów Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 17:23:26 bcik systemd[1]: Stopping mpd.service - Music Player Daemon... Oct 16 17:23:26 bcik sudo[15580]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 16 17:23:26 bcik sudo[15580]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:26 bcik volumio[15453]: info: UPNP Browser: Client initialized successfully Oct 16 17:23:26 bcik sudo[15580]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:26 bcik sudo[15581]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 16 17:23:26 bcik sudo[15581]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:26 bcik sudo[15578]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Oct 16 17:23:26 bcik sudo[15578]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:26 bcik systemd[1]: mpd.service: Deactivated successfully. Oct 16 17:23:26 bcik systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 16 17:23:26 bcik systemd[1]: mpd.socket: Deactivated successfully. Oct 16 17:23:26 bcik systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 16 17:23:26 bcik systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 16 17:23:26 bcik systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 16 17:23:26 bcik systemd[1]: Starting mpd.service - Music Player Daemon... Oct 16 17:23:26 bcik sudo[15578]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:26 bcik systemd[1]: mpd.service: Deactivated successfully. Oct 16 17:23:26 bcik systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 16 17:23:26 bcik systemd[1]: mpd.socket: Deactivated successfully. Oct 16 17:23:26 bcik systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 16 17:23:26 bcik systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 16 17:23:26 bcik systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 16 17:23:26 bcik systemd[1]: Starting mpd.service - Music Player Daemon... Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 16 17:23:26 bcik volumio[15453]: info: [1792164206609] CoreMusicLibrary::Adding element Last_100 Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 16 17:23:26 bcik volumio[15453]: info: [1792164206610] CoreMusicLibrary::Adding element Webradio Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 16 17:23:26 bcik volumio[15453]: info: Initializing BBC Radios Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: Creating Spotify config file Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik sudo[15596]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 16 17:23:26 bcik sudo[15596]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 16 17:23:26 bcik sudo[15596]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:26 bcik volumio[15525]: Starting albumart workers Oct 16 17:23:26 bcik volumio[15523]: Starting albumart workers Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 16 17:23:26 bcik volumio[15453]: info: [1792164206722] CoreMusicLibrary::Adding element Radio Browser Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 17:23:26 bcik volumio[15453]: Cannot find translation for source Radio Browser Oct 16 17:23:26 bcik volumio[15453]: info: Volumio Calling Home Oct 16 17:23:26 bcik volumio[15524]: Starting albumart workers Oct 16 17:23:26 bcik volumio[15453]: verbose: New 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 16 17:23:26 bcik volumio[15453]: info: MPD Permissions set Oct 16 17:23:26 bcik volumio[15453]: info: MPD Permissions set Oct 16 17:23:26 bcik volumio[15453]: 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 16 17:23:26 bcik volumio[15453]: info: Spotify config file written Oct 16 17:23:26 bcik volumio[15453]: verbose: New 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 16 17:23:26 bcik sudo[15615]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Oct 16 17:23:26 bcik sudo[15615]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:26 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:26 bcik go-librespot[15624]: go-librespot daemon starting... Oct 16 17:23:26 bcik sudo[15615]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:26 bcik go-librespot[15635]: time="2026-10-16T17:23:26+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:23:26 bcik go-librespot[15635]: time="2026-10-16T17:23:26+02:00" level=debug msg="app state loaded" Oct 16 17:23:26 bcik go-librespot[15635]: time="2026-10-16T17:23:26+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 17:23:26 bcik volumio[15453]: info: No need to fix Spotify hosts Oct 16 17:23:26 bcik volumio[15453]: verbose: New 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 16 17:23:26 bcik volumio[15453]: info: Volumio called home Oct 16 17:23:26 bcik volumio[15453]: info: Starting Shairport Sync Oct 16 17:23:26 bcik volumio[15453]: info: Starting Shairport Sync Oct 16 17:23:26 bcik volumio[15453]: info: Starting Shairport Sync Oct 16 17:23:26 bcik sudo[15645]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 16 17:23:26 bcik sudo[15645]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:26 bcik sudo[15644]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 16 17:23:26 bcik sudo[15644]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:26 bcik sudo[15647]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 16 17:23:26 bcik sudo[15647]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:26 bcik go-librespot[15635]: time="2026-10-16T17:23:26+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 16 17:23:26 bcik go-librespot[15635]: time="2026-10-16T17:23:26+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 16 17:23:26 bcik go-librespot[15635]: time="2026-10-16T17:23:26+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 16 17:23:26 bcik volumio[15453]: verbose: New 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 16 17:23:26 bcik systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 16 17:23:26 bcik systemd[1]: shairport-sync.service: Deactivated successfully. Oct 16 17:23:26 bcik systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 16 17:23:26 bcik systemd[1]: shairport-sync.service: Consumed 1.544s CPU time. Oct 16 17:23:27 bcik go-librespot[15635]: time="2026-10-16T17:23:26+02:00" level=info msg="zeroconf server listening on port 36349" Oct 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: info: An error occurred while refreshing Spotify Token Error: Bad Request Oct 16 17:23:27 bcik systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 16 17:23:27 bcik sudo[15644]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:27 bcik sudo[15647]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:27 bcik sudo[15645]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:27 bcik volumio[15453]: info: CoreCommandRouter::volumioGetState Oct 16 17:23:27 bcik volumio[15453]: info: CorePlayQueue::getTrack 0 Oct 16 17:23:27 bcik volumio[15453]: info: Shairport-Sync Started Oct 16 17:23:27 bcik volumio[15453]: Error adding Membership: Error: addMembership EINVAL Oct 16 17:23:27 bcik volumio[15453]: info: Shairport-Sync Started Oct 16 17:23:27 bcik volumio[15453]: info: Shairport-Sync Started Oct 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik go-librespot[15635]: time="2026-10-16T17:23:27+02:00" level=debug msg="obtained new client token: AAFIhlCT8+Kh5PzApGNIXNL0+sOVm5n4MbJ2mpoMoliikBeDngqfjThtnEE+SPzp6zjJfQPyI+WEo4sOzycjrcnNTtGs6YcqyYnYox6l6uCHvdxczhah0jdenUBx1yCpOTgaD83WiMx9Dbq6vgUFWtszGTviUHa4aG06U/ZGVMUDjsO4s257psX+H+oUmZb3RVGsHOgbTx0TScn06NFgxcBt2P2eG49ChNFDx8grjU5z+22w56qr" Oct 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik go-librespot[15635]: time="2026-10-16T17:23:27+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: info: Discovery: adding f1ed5fb6-e21d-47c8-819b-29842600355e Oct 16 17:23:27 bcik volumio[15453]: info: Discovery: Found device Bącik Oct 16 17:23:27 bcik volumio[15453]: info: CoreCommandRouter::volumioGetState Oct 16 17:23:27 bcik volumio[15453]: info: CorePlayQueue::getTrack 0 Oct 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: info: Discovery: this is already registered, f1ed5fb6-e21d-47c8-819b-29842600355e Oct 16 17:23:27 bcik volumio[15453]: info: Discovery: Found device Bącik Oct 16 17:23:27 bcik volumio[15453]: info: CoreCommandRouter::volumioGetState Oct 16 17:23:27 bcik volumio[15453]: info: CorePlayQueue::getTrack 0 Oct 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik go-librespot[15635]: time="2026-10-16T17:23:27+02:00" level=debug msg="completed keyexchange" Oct 16 17:23:27 bcik go-librespot[15635]: time="2026-10-16T17:23:27+02:00" level=debug msg="completed challenge" Oct 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik go-librespot[15635]: time="2026-10-16T17:23:27+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik go-librespot[15635]: time="2026-10-16T17:23:27+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:23:27 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik mpd[15611]: 2026-10-16T17:23:27 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik systemd[1]: Started mpd.service - Music Player Daemon. Oct 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik sudo[15581]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:27 bcik sudo[15571]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: info: Completed starting Core Plugins Oct 16 17:23:27 bcik volumio[15453]: info: ------------------------------------------- Oct 16 17:23:27 bcik volumio[15453]: info: ----- MyVolumio plugins startup ---- Oct 16 17:23:27 bcik volumio[15453]: info: ------------------------------------------- Oct 16 17:23:27 bcik volumio[15453]: info: [MyVolumio PluginManager] Fetching plans data.... Oct 16 17:23:27 bcik volumio[15453]: verbose: New 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 16 17:23:27 bcik volumio[15453]: error: MPD error: The expression evaluated to a falsy value: Oct 16 17:23:27 bcik volumio[15453]: assert.ok(self.idling) Oct 16 17:23:27 bcik volumio[15453]: error: The expression evaluated to a falsy value: Oct 16 17:23:27 bcik volumio[15453]: assert.ok(self.idling) Oct 16 17:23:27 bcik volumio[15453]: info: MPD running with PID15611 Oct 16 17:23:27 bcik volumio[15453]: ,establishing connection Oct 16 17:23:27 bcik volumio[15453]: error: updateQueue error: null Oct 16 17:23:27 bcik volumio[15453]: error: updateQueue error: null Oct 16 17:23:29 bcik volumio-remote-updater[9031]: [2026-10-16 17:23:29] [connect] Successful connection Oct 16 17:23:29 bcik volumio-remote-updater[9031]: [2026-10-16 17:23:29] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1792164209 101 Oct 16 17:23:29 bcik volumio[15453]: 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 16 17:23:29 bcik volumio[15453]: info: go-librespot daemon successfully initialized Oct 16 17:23:30 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 101. Oct 16 17:23:30 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:30 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:30 bcik go-librespot[15686]: go-librespot daemon starting... Oct 16 17:23:30 bcik go-librespot[15687]: time="2026-10-16T17:23:30+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:23:30 bcik go-librespot[15687]: time="2026-10-16T17:23:30+02:00" level=debug msg="app state loaded" Oct 16 17:23:30 bcik go-librespot[15687]: time="2026-10-16T17:23:30+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:23:30 bcik go-librespot[15687]: time="2026-10-16T17:23:30+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 16 17:23:30 bcik go-librespot[15687]: time="2026-10-16T17:23:30+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 16 17:23:30 bcik go-librespot[15687]: time="2026-10-16T17:23:30+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 16 17:23:30 bcik go-librespot[15687]: time="2026-10-16T17:23:30+02:00" level=info msg="zeroconf server listening on port 46069" Oct 16 17:23:30 bcik go-librespot[15687]: time="2026-10-16T17:23:30+02:00" level=debug msg="obtained new client token: AAE5mJkrpnMb1yoJ5CCN8SJCLkboNZBGHP+G1M9sOzBqcJQ5UiD6rzlsmPg0PQeF93xg7SIUJIwBQb3e7tU2eO7xAC9v7l7F5wUdHD/0w2BXZHI0t7cDutzyaUepW7FmvXp/+G9iPgT1ccfVucQh+0uRjoICejChQlpEcPaBES17QtK4LK3NakjpGF8HTJ+qa4fODO7KYYPZ7LiWkBt++w4ahPr9xjxNlO1ql+jGO4SsxJYJPpxbirE=" Oct 16 17:23:30 bcik go-librespot[15687]: time="2026-10-16T17:23:30+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:23:30 bcik go-librespot[15687]: time="2026-10-16T17:23:30+02:00" level=debug msg="completed keyexchange" Oct 16 17:23:30 bcik go-librespot[15687]: time="2026-10-16T17:23:30+02:00" level=debug msg="completed challenge" Oct 16 17:23:30 bcik go-librespot[15687]: time="2026-10-16T17:23:30+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:23:30 bcik go-librespot[15687]: time="2026-10-16T17:23:30+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 16 17:23:30 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:23:30 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:23:32 bcik volumio[15453]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Oct 16 17:23:32 bcik volumio[15453]: info: Initializing connection to go-librespot Websocket Oct 16 17:23:32 bcik volumio[15453]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:23:33 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 102. Oct 16 17:23:33 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:33 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:33 bcik go-librespot[15696]: go-librespot daemon starting... Oct 16 17:23:33 bcik go-librespot[15697]: time="2026-10-16T17:23:33+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:23:33 bcik go-librespot[15697]: time="2026-10-16T17:23:33+02:00" level=debug msg="app state loaded" Oct 16 17:23:33 bcik go-librespot[15697]: time="2026-10-16T17:23:33+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:23:33 bcik go-librespot[15697]: time="2026-10-16T17:23:33+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 16 17:23:33 bcik go-librespot[15697]: time="2026-10-16T17:23:33+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 16 17:23:33 bcik go-librespot[15697]: time="2026-10-16T17:23:33+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 16 17:23:33 bcik go-librespot[15697]: time="2026-10-16T17:23:33+02:00" level=info msg="zeroconf server listening on port 42039" Oct 16 17:23:33 bcik go-librespot[15697]: time="2026-10-16T17:23:33+02:00" level=debug msg="obtained new client token: AAFeqhk8O5uP11nFX9PiDWb+NED8/N+3Wx3Hfyc3BNJZ+IeM8wXAm+/83vBMxPpeyx+tSbWPdQoCQCcnvSpLle+7Yscpnphs3OfUOX5EtUP1iR1hJClflzQaq3y6vUJksJ/7LiJxjgeFkVEY/1caETnr/vpz8IWeNziOUFRaFOfnS0CJvuCRZANyuQv4AvRliijTD8NBa9R9socNsKSp6oLRbm77bZZpEf5kQ4/E7wqXLENU1VUIpw8=" Oct 16 17:23:34 bcik go-librespot[15697]: time="2026-10-16T17:23:34+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:23:34 bcik go-librespot[15697]: time="2026-10-16T17:23:34+02:00" level=debug msg="completed keyexchange" Oct 16 17:23:34 bcik go-librespot[15697]: time="2026-10-16T17:23:34+02:00" level=debug msg="completed challenge" Oct 16 17:23:34 bcik go-librespot[15697]: time="2026-10-16T17:23:34+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:23:34 bcik go-librespot[15697]: time="2026-10-16T17:23:34+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 16 17:23:34 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:23:34 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Oct 16 17:23:35 bcik volumio[15453]: info: Adding plugin bluetooth to MyMusic Plugins Oct 16 17:23:35 bcik volumio[15453]: info: Adding plugin multiroom to MyMusic Plugins Oct 16 17:23:35 bcik volumio[15453]: info: Adding plugin metavolumio to MyMusic Plugins Oct 16 17:23:35 bcik volumio[15453]: info: Adding plugin cd_controller to MyMusic Plugins Oct 16 17:23:35 bcik volumio[15453]: info: Adding plugin qobuzconnect to MyMusic Plugins Oct 16 17:23:35 bcik volumio[15453]: info: Adding plugin smart_inputs to MyMusic Plugins Oct 16 17:23:35 bcik volumio[15453]: info: Adding plugin tidalconnect to MyMusic Plugins Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Oct 16 17:23:35 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:35 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:35 bcik volumio[15453]: info: Starting MyVolumio Remote Streaming Endpoints Oct 16 17:23:35 bcik volumio[15453]: info: MyVolumio login type: Token Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Oct 16 17:23:35 bcik volumio[15453]: info: Streaming services startup Oct 16 17:23:35 bcik volumio[15453]: info: Starting Streaming Daemon Oct 16 17:23:35 bcik sudo[15721]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 16 17:23:35 bcik sudo[15721]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:35 bcik volumio[15453]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Oct 16 17:23:35 bcik sudo[15721]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:35 bcik sudo[15728]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 16 17:23:35 bcik sudo[15728]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:35 bcik volumio[15453]: error: Cannot start Volumio Streaming Daemon Oct 16 17:23:35 bcik volumio[15453]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 16 17:23:35 bcik volumio[15453]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 16 17:23:35 bcik sudo[15730]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 16 17:23:35 bcik sudo[15730]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:35 bcik sudo[15730]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:35 bcik sudo[15728]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:35 bcik sudo[15734]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Oct 16 17:23:35 bcik sudo[15734]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:35 bcik sudo[15734]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:35 bcik volumio[15453]: info: Upmpdcli Daemon Started Oct 16 17:23:35 bcik volumio[15453]: info: Initializing connection to go-librespot Websocket Oct 16 17:23:35 bcik volumio[15453]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:23:36 bcik volumio[15453]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Oct 16 17:23:36 bcik volumio[15453]: info: MyVolumio token set successfully Oct 16 17:23:36 bcik volumio[15453]: info: MYVOLUMIO: Adding device Oct 16 17:23:36 bcik volumio[15453]: info: MYVOLUMIO: Evaluating Server Oct 16 17:23:37 bcik volumio[15453]: info: MyVolumio status changed Oct 16 17:23:37 bcik volumio[15453]: info: Streaming services startup Oct 16 17:23:37 bcik volumio[15453]: info: Starting Streaming Daemon Oct 16 17:23:37 bcik volumio[15453]: info: Removing browser output: myVolumio user plan is not superstar Oct 16 17:23:37 bcik volumio[15453]: info: Removing audio output: Oct 16 17:23:37 bcik volumio[15453]: info: Stoppping Tunnel 1 Oct 16 17:23:37 bcik sudo[15757]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 16 17:23:37 bcik sudo[15757]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:37 bcik sudo[15759]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Oct 16 17:23:37 bcik sudo[15759]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:23:37 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 16 17:23:37 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 16 17:23:37 bcik sudo[15757]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:37 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 16 17:23:37 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 16 17:23:37 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 16 17:23:37 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 16 17:23:37 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 16 17:23:37 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 16 17:23:37 bcik volumio[15453]: error: Cannot start Volumio Streaming Daemon Oct 16 17:23:37 bcik sudo[15759]: pam_unix(sudo:session): session closed for user root Oct 16 17:23:37 bcik volumio[15453]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 16 17:23:37 bcik volumio[15453]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 16 17:23:37 bcik volumio[15453]: info: Remote SSH Stopped Oct 16 17:23:37 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 103. Oct 16 17:23:37 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:37 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:37 bcik go-librespot[15763]: go-librespot daemon starting... Oct 16 17:23:37 bcik go-librespot[15764]: time="2026-10-16T17:23:37+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:23:37 bcik go-librespot[15764]: time="2026-10-16T17:23:37+02:00" level=debug msg="app state loaded" Oct 16 17:23:37 bcik go-librespot[15764]: time="2026-10-16T17:23:37+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:23:37 bcik volumio[15453]: info: Setting Geolocation for MyVolumio to eu6 Oct 16 17:23:37 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:37 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:37 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:37 bcik go-librespot[15764]: time="2026-10-16T17:23:37+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Oct 16 17:23:37 bcik go-librespot[15764]: time="2026-10-16T17:23:37+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Oct 16 17:23:37 bcik go-librespot[15764]: time="2026-10-16T17:23:37+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Oct 16 17:23:37 bcik go-librespot[15764]: time="2026-10-16T17:23:37+02:00" level=info msg="zeroconf server listening on port 33079" Oct 16 17:23:37 bcik go-librespot[15764]: time="2026-10-16T17:23:37+02:00" level=debug msg="obtained new client token: AAEtc9/nTGOmt/Ybs45pVACqxvQSdwxerUA9RtopYz2/NJ7p1h7yq+2X71aViqPhrSVwuCvEseE9VNW1YAj7DdSCP+Z4rXD2mPIh4KnJIfb9CdoLram7CYZLuiTm02cPVPP/FMDjbfVe+nfHxoNic5bcGWVJJZvTnuUJhYNf1Jm96+p8IjpUeqeOmudydHH9vAGB3Q+BYUBEdam/3b77L+e2Ex/Ihr9+UQ2vTc6ZCGcCyN6XzYbhX2U=" Oct 16 17:23:37 bcik go-librespot[15764]: time="2026-10-16T17:23:37+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 16 17:23:37 bcik go-librespot[15764]: time="2026-10-16T17:23:37+02:00" level=debug msg="completed keyexchange" Oct 16 17:23:37 bcik go-librespot[15764]: time="2026-10-16T17:23:37+02:00" level=debug msg="completed challenge" Oct 16 17:23:37 bcik go-librespot[15764]: time="2026-10-16T17:23:37+02:00" level=info msg="authenticated AP" username="la***pl" Oct 16 17:23:37 bcik volumio[15453]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Oct 16 17:23:37 bcik go-librespot[15764]: time="2026-10-16T17:23:37+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 16 17:23:37 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:23:37 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:23:38 bcik volumio[15453]: info: Updating MyVolumio device info Oct 16 17:23:38 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:38 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:38 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:38 bcik volumio[15453]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Oct 16 17:23:38 bcik volumio[15453]: info: Initializing connection to go-librespot Websocket Oct 16 17:23:38 bcik volumio[15453]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 16 17:23:40 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 104. Oct 16 17:23:40 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:40 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 16 17:23:40 bcik go-librespot[15774]: go-librespot daemon starting... Oct 16 17:23:40 bcik go-librespot[15775]: time="2026-10-16T17:23:40+02:00" level=info msg="running go-librespot 0.6.2" Oct 16 17:23:40 bcik go-librespot[15775]: time="2026-10-16T17:23:40+02:00" level=debug msg="app state loaded" Oct 16 17:23:40 bcik go-librespot[15775]: time="2026-10-16T17:23:40+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 16 17:23:40 bcik go-librespot[15775]: time="2026-10-16T17:23:40+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 16 17:23:40 bcik go-librespot[15775]: time="2026-10-16T17:23:40+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 16 17:23:40 bcik go-librespot[15775]: time="2026-10-16T17:23:40+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 16 17:23:40 bcik go-librespot[15775]: time="2026-10-16T17:23:40+02:00" level=info msg="zeroconf server listening on port 43053" Oct 16 17:23:41 bcik volumio[15453]: info: MYVOLUMIO: Adding device Oct 16 17:23:41 bcik volumio[15453]: info: MYVOLUMIO: Evaluating Server Oct 16 17:23:41 bcik volumio[15453]: info: Initializing connection to go-librespot Websocket Oct 16 17:23:41 bcik go-librespot[15775]: time="2026-10-16T17:23:41+02:00" level=debug msg="new websocket client" Oct 16 17:23:41 bcik volumio[15453]: info: Connection to go-librespot Websocket established Oct 16 17:23:42 bcik volumio[15453]: info: Setting Geolocation for MyVolumio to eu6 Oct 16 17:23:42 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:42 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:42 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:42 bcik volumio[15453]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Oct 16 17:23:43 bcik volumio[15453]: info: Updating MyVolumio device info Oct 16 17:23:43 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:43 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:43 bcik volumio[15453]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 17:23:43 bcik volumio[15453]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Oct 16 17:23:44 bcik volumio[15453]: info: Getting Spotify volume Oct 16 17:23:44 bcik volumio[15453]: 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 16 17:23:44 bcik volumio[15453]: info: CoreCommandRouter::volumioGetState Oct 16 17:23:44 bcik volumio[15453]: info: CorePlayQueue::getTrack 0 Oct 16 17:23:44 bcik volumio[15453]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 Oct 16 17:23:44 bcik volumio[15453]: SPOTIFY: SPOTIFY VOLUME undefined Oct 16 17:23:44 bcik volumio[15453]: SPOTIFY: VOLUMIO VOLUME 41 Oct 16 17:23:44 bcik volumio[15453]: info: Aligning Spotify Volume to Volumio Volume Oct 16 17:23:44 bcik volumio[15453]: info: CoreCommandRouter::volumioGetState Oct 16 17:23:44 bcik volumio[15453]: info: CorePlayQueue::getTrack 0 Oct 16 17:23:44 bcik volumio[15453]: info: Setting Spotify Volume from Volumio: 41 Oct 16 17:23:46 bcik go-librespot[15775]: time="2026-10-16T17:23:46+02:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: invalid status code from clienttoken: 503" Oct 16 17:23:46 bcik volumio[15453]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 16 17:23:46 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 16 17:23:46 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 16 17:23:46 bcik volumio[15453]: Error: socket hang up Oct 16 17:23:46 bcik volumio[15453]: at connResetException (node:internal/errors:720:14) Oct 16 17:23:46 bcik volumio[15453]: at Socket.socketOnEnd (node:_http_client:519:23) Oct 16 17:23:46 bcik volumio[15453]: at Socket.emit (node:events:526:35) Oct 16 17:23:46 bcik volumio[15453]: at endReadableNT (node:internal/streams/readable:1376:12) Oct 16 17:23:46 bcik volumio[15453]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Oct 16 17:23:46 bcik volumio[15453]: code: 'ECONNRESET', Oct 16 17:23:46 bcik volumio[15453]: response: undefined Oct 16 17:23:46 bcik volumio[15453]: } Oct 16 17:23:46 bcik volumio[15453]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 16 17:23:46 bcik sudo[15830]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-16 17:22' Oct 16 17:23:46 bcik sudo[15830]: 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"