Aug 31 17:01:00 bcik volumio[19839]: info: Initializing connection to go-librespot Websocket Aug 31 17:01:00 bcik volumio[19839]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 17:01:02 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 217. Aug 31 17:01:02 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:01:02 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:01:02 bcik go-librespot[20347]: go-librespot daemon starting... Aug 31 17:01:02 bcik go-librespot[20348]: time="2026-08-31T17:01:02+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 17:01:02 bcik go-librespot[20348]: time="2026-08-31T17:01:02+02:00" level=debug msg="app state loaded" Aug 31 17:01:02 bcik go-librespot[20348]: time="2026-08-31T17:01:02+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 17:01:02 bcik go-librespot[20348]: time="2026-08-31T17:01:02+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 31 17:01:02 bcik go-librespot[20348]: time="2026-08-31T17:01:02+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 31 17:01:02 bcik go-librespot[20348]: time="2026-08-31T17:01:02+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 31 17:01:02 bcik go-librespot[20348]: time="2026-08-31T17:01:02+02:00" level=info msg="zeroconf server listening on port 36067" Aug 31 17:01:02 bcik go-librespot[20348]: time="2026-08-31T17:01:02+02:00" level=debug msg="obtained new client token: AAEj7E0CLRzvr+X7OnbtglD2iaApKGd5/8d5Ax5lcixHhcXLuMq+pAhZB1ow9L78dLfu62YioJdQQmZ4KmmlfDZ1NPfMJvdGEAkEdskSd0XcWI0OfNAkSSjLuDNN6dm1v3nbRZsQd35NnO4itX5qjagdLhCa9tQTv4ZSqZx6YpOoQ1HF/AM5AMJez9a1uBmzj+Z06Nf+X4FUJYNPp/LbtPRYPjEyFdtcPbEG7BkJfeToh+FTrcZEliU=" Aug 31 17:01:02 bcik go-librespot[20348]: time="2026-08-31T17:01:02+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 17:01:02 bcik go-librespot[20348]: time="2026-08-31T17:01:02+02:00" level=debug msg="completed keyexchange" Aug 31 17:01:02 bcik go-librespot[20348]: time="2026-08-31T17:01:02+02:00" level=debug msg="completed challenge" Aug 31 17:01:02 bcik go-librespot[20348]: time="2026-08-31T17:01:02+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 17:01:02 bcik go-librespot[20348]: time="2026-08-31T17:01:02+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 17:01:02 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 17:01:02 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 17:01:03 bcik volumio[19839]: info: Initializing connection to go-librespot Websocket Aug 31 17:01:03 bcik volumio[19839]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 17:01:05 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 218. Aug 31 17:01:05 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:01:05 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:01:05 bcik go-librespot[20372]: go-librespot daemon starting... Aug 31 17:01:05 bcik go-librespot[20373]: time="2026-08-31T17:01:05+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 17:01:05 bcik go-librespot[20373]: time="2026-08-31T17:01:05+02:00" level=debug msg="app state loaded" Aug 31 17:01:05 bcik go-librespot[20373]: time="2026-08-31T17:01:05+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 17:01:05 bcik go-librespot[20373]: time="2026-08-31T17:01:05+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 31 17:01:05 bcik go-librespot[20373]: time="2026-08-31T17:01:05+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 31 17:01:05 bcik go-librespot[20373]: time="2026-08-31T17:01:05+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 31 17:01:05 bcik go-librespot[20373]: time="2026-08-31T17:01:05+02:00" level=info msg="zeroconf server listening on port 46297" Aug 31 17:01:05 bcik go-librespot[20373]: time="2026-08-31T17:01:05+02:00" level=debug msg="obtained new client token: AAEvQpLFZuM6y6eYzTFplhbWEm7LRs4PnDAYRdPNRB7ho38g/9RSiZLxcAuacnz185X0y2JJeSXXPUNWfOQVZjO6H+LX+a2nWYu+ojjr/ouSMN6pq5AaVBCSRr1ieQEa3LddhgSACrYUjL6AOSdNE6AEkjZQTIkdXeG7lvNiQI0fHbwuG27mEW5hWBMWqJiiznmqVpmB9Oa/+F10vcEOetJnowOAvjJ2gpZ/Wy4yne798l7mq7hrEtk=" Aug 31 17:01:05 bcik go-librespot[20373]: time="2026-08-31T17:01:05+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 17:01:05 bcik go-librespot[20373]: time="2026-08-31T17:01:05+02:00" level=debug msg="completed keyexchange" Aug 31 17:01:05 bcik go-librespot[20373]: time="2026-08-31T17:01:05+02:00" level=debug msg="completed challenge" Aug 31 17:01:05 bcik go-librespot[20373]: time="2026-08-31T17:01:05+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 17:01:05 bcik go-librespot[20373]: time="2026-08-31T17:01:05+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 17:01:05 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 17:01:05 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 17:01:06 bcik volumio[19839]: info: Initializing connection to go-librespot Websocket Aug 31 17:01:06 bcik volumio[19839]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 17:01:09 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 219. Aug 31 17:01:09 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:01:09 bcik volumio[19839]: info: Initializing connection to go-librespot Websocket Aug 31 17:01:09 bcik volumio[19839]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 17:01:09 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:01:09 bcik go-librespot[20382]: go-librespot daemon starting... Aug 31 17:01:09 bcik go-librespot[20383]: time="2026-08-31T17:01:09+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 17:01:09 bcik go-librespot[20383]: time="2026-08-31T17:01:09+02:00" level=debug msg="app state loaded" Aug 31 17:01:09 bcik go-librespot[20383]: time="2026-08-31T17:01:09+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 17:01:09 bcik go-librespot[20383]: time="2026-08-31T17:01:09+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 31 17:01:09 bcik go-librespot[20383]: time="2026-08-31T17:01:09+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 31 17:01:09 bcik go-librespot[20383]: time="2026-08-31T17:01:09+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 31 17:01:09 bcik go-librespot[20383]: time="2026-08-31T17:01:09+02:00" level=info msg="zeroconf server listening on port 40961" Aug 31 17:01:09 bcik go-librespot[20383]: time="2026-08-31T17:01:09+02:00" level=debug msg="obtained new client token: AAFui6b0vHSF/g9fz1+e685M1P9Tun/PVK6Lqdd2WtNtMk+mz4errePr3cnaghKl9ucm1YW5dVQyyL5VImesZntMfS0nQ5Z4nD7/DHj4v1tmsdt97h9h5nIYD64HNKi5Zi5dZ+K9W+AVLxjIYEUg6cA/MDo73haMaPCF1kE05mjIwIcFdrXBl11YmUAj3Ummjf/kQx3INYgHN3NdEg4VzrySQGKhxJ8Rg2YdlCgCemFyOUmpgz4NcNo=" Aug 31 17:01:09 bcik go-librespot[20383]: time="2026-08-31T17:01:09+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 17:01:09 bcik go-librespot[20383]: time="2026-08-31T17:01:09+02:00" level=debug msg="completed keyexchange" Aug 31 17:01:09 bcik go-librespot[20383]: time="2026-08-31T17:01:09+02:00" level=debug msg="completed challenge" Aug 31 17:01:09 bcik go-librespot[20383]: time="2026-08-31T17:01:09+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 17:01:09 bcik go-librespot[20383]: time="2026-08-31T17:01:09+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 17:01:09 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 17:01:09 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 17:01:09 bcik systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Aug 31 17:01:10 bcik systemd[1]: setdatetime-helper.service: Deactivated successfully. Aug 31 17:01:10 bcik systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Aug 31 17:01:12 bcik volumio[19839]: info: Initializing connection to go-librespot Websocket Aug 31 17:01:12 bcik volumio[19839]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 17:01:13 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 220. Aug 31 17:01:13 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:01:13 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:01:13 bcik go-librespot[20418]: go-librespot daemon starting... Aug 31 17:01:13 bcik go-librespot[20419]: time="2026-08-31T17:01:13+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 17:01:13 bcik go-librespot[20419]: time="2026-08-31T17:01:13+02:00" level=debug msg="app state loaded" Aug 31 17:01:13 bcik go-librespot[20419]: time="2026-08-31T17:01:13+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 17:01:13 bcik go-librespot[20419]: time="2026-08-31T17:01: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-gae2.spotify.com:80]" Aug 31 17:01:13 bcik go-librespot[20419]: time="2026-08-31T17:01:13+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 17:01:13 bcik go-librespot[20419]: time="2026-08-31T17:01:13+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 17:01:13 bcik go-librespot[20419]: time="2026-08-31T17:01:13+02:00" level=info msg="zeroconf server listening on port 40801" Aug 31 17:01:13 bcik go-librespot[20419]: time="2026-08-31T17:01:13+02:00" level=debug msg="obtained new client token: AAEojLZo727c2YAUpWoDizDxzA5itjNL1KHwI2o4HW675GOArV1HHf6EuRYnXoPyO81Z69OYptvHeCetaJSk0DuMlZdQFCv89exO67MJ7DTxU3N2JJezI1XWXJ3gJLVXy1Lyh7bZQuHOQX8sBxZ4KDWwBa2G1316BaCjt0GSxHkB9UJeK+MiKyKs8CAEPRm+1V934fUUAWhJ4a+a4PiNFR4t2m3EdaGi4z8Fpg446sbcqWAWy3BO" Aug 31 17:01:13 bcik go-librespot[20419]: time="2026-08-31T17:01:13+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 17:01:13 bcik go-librespot[20419]: time="2026-08-31T17:01:13+02:00" level=debug msg="completed keyexchange" Aug 31 17:01:13 bcik go-librespot[20419]: time="2026-08-31T17:01:13+02:00" level=debug msg="completed challenge" Aug 31 17:01:13 bcik go-librespot[20419]: time="2026-08-31T17:01:13+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 17:01:13 bcik go-librespot[20419]: time="2026-08-31T17:01:13+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 17:01:13 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 17:01:13 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 17:01:15 bcik volumio[19839]: info: Initializing connection to go-librespot Websocket Aug 31 17:01:15 bcik volumio[19839]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 17:01:17 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 221. Aug 31 17:01:17 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:01:17 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:01:17 bcik go-librespot[20442]: go-librespot daemon starting... Aug 31 17:01:17 bcik go-librespot[20443]: time="2026-08-31T17:01:17+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 17:01:17 bcik go-librespot[20443]: time="2026-08-31T17:01:17+02:00" level=debug msg="app state loaded" Aug 31 17:01:17 bcik go-librespot[20443]: time="2026-08-31T17:01:17+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 17:01:17 bcik go-librespot[20443]: time="2026-08-31T17:01: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-gew1.spotify.com:80]" Aug 31 17:01:17 bcik go-librespot[20443]: time="2026-08-31T17:01:17+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 31 17:01:17 bcik go-librespot[20443]: time="2026-08-31T17:01:17+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 31 17:01:17 bcik go-librespot[20443]: time="2026-08-31T17:01:17+02:00" level=info msg="zeroconf server listening on port 37071" Aug 31 17:01:17 bcik go-librespot[20443]: time="2026-08-31T17:01:17+02:00" level=debug msg="obtained new client token: AAH8TN29z2cz6+rRsdgamkZa60qhyLRcltU6o3aBufP1XJMVRxmkAFioDAMeNVdVmdDAbNSTOUv77aBbyESxpuwNknyzOANiQ5l1AJoKbtHX86nue8IMq/dyfiqaiaJPZrYLrW0MJp/kaMzyibK9qKxYwCo2++ldrottDwrQL/XSrzcFNaa8SaH+9wJ3WhsPVmjRTO0JvVrXGrA8cNnXJKYmKEIF6t6Q7gkF1wQpUzUw7dGiSyB5" Aug 31 17:01:17 bcik go-librespot[20443]: time="2026-08-31T17:01:17+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 17:01:17 bcik go-librespot[20443]: time="2026-08-31T17:01:17+02:00" level=debug msg="completed keyexchange" Aug 31 17:01:17 bcik go-librespot[20443]: time="2026-08-31T17:01:17+02:00" level=debug msg="completed challenge" Aug 31 17:01:17 bcik go-librespot[20443]: time="2026-08-31T17:01:17+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 17:01:17 bcik go-librespot[20443]: time="2026-08-31T17:01:17+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 17:01:17 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 17:01:17 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 17:01:18 bcik volumio[19839]: info: Initializing connection to go-librespot Websocket Aug 31 17:01:18 bcik volumio[19839]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 17:01:20 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 222. Aug 31 17:01:20 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:01:20 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:01:20 bcik go-librespot[20452]: go-librespot daemon starting... Aug 31 17:01:20 bcik go-librespot[20453]: time="2026-08-31T17:01:20+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 17:01:20 bcik go-librespot[20453]: time="2026-08-31T17:01:20+02:00" level=debug msg="app state loaded" Aug 31 17:01:20 bcik go-librespot[20453]: time="2026-08-31T17:01:20+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 17:01:20 bcik go-librespot[20453]: time="2026-08-31T17:01: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-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 17:01:20 bcik go-librespot[20453]: time="2026-08-31T17:01:20+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 17:01:20 bcik go-librespot[20453]: time="2026-08-31T17:01:20+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 17:01:20 bcik go-librespot[20453]: time="2026-08-31T17:01:20+02:00" level=info msg="zeroconf server listening on port 35439" Aug 31 17:01:20 bcik go-librespot[20453]: time="2026-08-31T17:01:20+02:00" level=debug msg="obtained new client token: AAEMFfPub9SHcF999hokEO8EEsZ4BeyXCd92MyMG4d8I6DSkKkAqNy2X2th8TbTnzjvfre0H4a64DQbMYqtOGHIMcDKQLE1O7Xpjx5YKWj1/wBoUzbe36lo/82dOt3pjeKa0HleB91j98buu2NJci4nYbLCgGR0+++0gmutjiqajlUKHbd5irp3tWZ61Gpyqb3ps1OAv2z+SUTU3hqriYY2pRVM6feqI5Mlis2XGB/u4muPLrqe7AW8=" Aug 31 17:01:20 bcik go-librespot[20453]: time="2026-08-31T17:01:20+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 17:01:20 bcik go-librespot[20453]: time="2026-08-31T17:01:20+02:00" level=debug msg="completed keyexchange" Aug 31 17:01:20 bcik go-librespot[20453]: time="2026-08-31T17:01:20+02:00" level=debug msg="completed challenge" Aug 31 17:01:20 bcik go-librespot[20453]: time="2026-08-31T17:01:20+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 17:01:20 bcik go-librespot[20453]: time="2026-08-31T17:01:20+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 17:01:20 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 17:01:20 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 17:01:21 bcik volumio[19839]: info: Initializing connection to go-librespot Websocket Aug 31 17:01:21 bcik volumio[19839]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 17:01:24 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 223. Aug 31 17:01:24 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:01:24 bcik volumio[19839]: info: Initializing connection to go-librespot Websocket Aug 31 17:01:24 bcik volumio[19839]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 17:01:24 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:01:24 bcik go-librespot[20476]: go-librespot daemon starting... Aug 31 17:01:24 bcik go-librespot[20477]: time="2026-08-31T17:01:24+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 17:01:24 bcik go-librespot[20477]: time="2026-08-31T17:01:24+02:00" level=debug msg="app state loaded" Aug 31 17:01:24 bcik go-librespot[20477]: time="2026-08-31T17:01:24+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 17:01:24 bcik go-librespot[20477]: time="2026-08-31T17:01: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]" Aug 31 17:01:24 bcik go-librespot[20477]: time="2026-08-31T17:01: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]" Aug 31 17:01:24 bcik go-librespot[20477]: time="2026-08-31T17:01: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]" Aug 31 17:01:24 bcik go-librespot[20477]: time="2026-08-31T17:01:24+02:00" level=info msg="zeroconf server listening on port 46759" Aug 31 17:01:24 bcik go-librespot[20477]: time="2026-08-31T17:01:24+02:00" level=debug msg="obtained new client token: AAEhp5GWDv3IEoJ+GBQ5gojGBVQ8Wt7PE0SCl567P/7LYOEK0Tm6cn6bXW0rnqIfVLnsCiz1gAgeeEr6bIU0InWvXsmXbFZpH5PrE9PEJwOAmD4ACvO9oiYZmEBSKRIw4/MidkEa4anxOHyGnosGnvlr0jcN35HnGcsF9fGfdHMsjnt3mW+DyokzQMII650LQ8QuUrztRS0vV6JCjHGkc0JUOqmr38saNGRipkJ3NDc2Hx0lNEdA" Aug 31 17:01:24 bcik go-librespot[20477]: time="2026-08-31T17:01:24+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Aug 31 17:01:24 bcik go-librespot[20477]: time="2026-08-31T17:01:24+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Aug 31 17:01:24 bcik go-librespot[20477]: time="2026-08-31T17:01:24+02:00" level=debug msg="completed keyexchange" Aug 31 17:01:24 bcik go-librespot[20477]: time="2026-08-31T17:01:24+02:00" level=debug msg="completed challenge" Aug 31 17:01:24 bcik go-librespot[20477]: time="2026-08-31T17:01:24+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 17:01:24 bcik go-librespot[20477]: time="2026-08-31T17:01:24+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 17:01:24 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 17:01:24 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 17:01:27 bcik volumio[19839]: info: Initializing connection to go-librespot Websocket Aug 31 17:01:27 bcik volumio[19839]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 17:01:27 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 224. Aug 31 17:01:27 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:01:27 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:01:27 bcik go-librespot[20487]: go-librespot daemon starting... Aug 31 17:01:27 bcik go-librespot[20488]: time="2026-08-31T17:01:27+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 17:01:27 bcik go-librespot[20488]: time="2026-08-31T17:01:27+02:00" level=debug msg="app state loaded" Aug 31 17:01:27 bcik go-librespot[20488]: time="2026-08-31T17:01:27+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 17:01:27 bcik go-librespot[20488]: time="2026-08-31T17:01:27+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 17:01:27 bcik go-librespot[20488]: time="2026-08-31T17:01:27+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 17:01:27 bcik go-librespot[20488]: time="2026-08-31T17:01:27+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 17:01:27 bcik go-librespot[20488]: time="2026-08-31T17:01:27+02:00" level=info msg="zeroconf server listening on port 39665" Aug 31 17:01:27 bcik go-librespot[20488]: time="2026-08-31T17:01:27+02:00" level=debug msg="obtained new client token: AAEMCOvJLFFRCEJThjF8jn4LALT7Yb2+6YnVm9+av/NLi0GcqjP77NJnQ+fdKg58jsUMUpN5gkwBmTKMAMDfRx3kprotjSIiz1oclaGPfXI168ntbgtsObOUT61nxNoyN8DV3p20Oirl+YAHuQ6IGaEtk3DvJl81t5qXIViuPX7ZMpvszlA4zSfn0eMqJfCReq9+pvfDYArj7pvEzueGzlI7gLGKoYs3K1MEMNcxBg8bY+rrjL/1wOE=" Aug 31 17:01:27 bcik go-librespot[20488]: time="2026-08-31T17:01:27+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 17:01:27 bcik go-librespot[20488]: time="2026-08-31T17:01:27+02:00" level=debug msg="completed keyexchange" Aug 31 17:01:27 bcik go-librespot[20488]: time="2026-08-31T17:01:27+02:00" level=debug msg="completed challenge" Aug 31 17:01:27 bcik go-librespot[20488]: time="2026-08-31T17:01:27+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 17:01:28 bcik go-librespot[20488]: time="2026-08-31T17:01:28+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 17:01:28 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 17:01:28 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 17:01:30 bcik volumio[19839]: info: Initializing connection to go-librespot Websocket Aug 31 17:01:30 bcik volumio[19839]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 17:01:31 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 225. Aug 31 17:01:31 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:01:31 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:01:31 bcik go-librespot[20497]: go-librespot daemon starting... Aug 31 17:01:31 bcik go-librespot[20498]: time="2026-08-31T17:01:31+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 17:01:31 bcik go-librespot[20498]: time="2026-08-31T17:01:31+02:00" level=debug msg="app state loaded" Aug 31 17:01:31 bcik go-librespot[20498]: time="2026-08-31T17:01:31+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 17:01:31 bcik go-librespot[20498]: time="2026-08-31T17:01:31+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 17:01:31 bcik go-librespot[20498]: time="2026-08-31T17:01:31+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 17:01:31 bcik go-librespot[20498]: time="2026-08-31T17:01:31+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 17:01:31 bcik go-librespot[20498]: time="2026-08-31T17:01:31+02:00" level=info msg="zeroconf server listening on port 39255" Aug 31 17:01:31 bcik go-librespot[20498]: time="2026-08-31T17:01:31+02:00" level=debug msg="obtained new client token: AAER40YgcDlZAhnVfIxTYpLqj3a9qasB4g04y0P22I2yQd/R3sa4bvPMnBQVeRk2bRwt1AEitp0cSohICt8WF1XIQbAa2lMC9YzzKGhidEn/YvlEiFk1XTAWonqy0JjOUpRGO8017cu3dmPOQxZHVoF5rzJx88XEDwE29hXYbGRolOasll3x6zKvBRN3keghLIn3QuEjrvG/puUmGKhXW8ybxgGneIfDkc4D1+jduv/tQBPFhyt9Op4=" Aug 31 17:01:31 bcik go-librespot[20498]: time="2026-08-31T17:01:31+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 17:01:33 bcik volumio[19839]: info: Initializing connection to go-librespot Websocket Aug 31 17:01:33 bcik go-librespot[20498]: time="2026-08-31T17:01:33+02:00" level=debug msg="new websocket client" Aug 31 17:01:33 bcik volumio[19839]: info: Connection to go-librespot Websocket established Aug 31 17:01:34 bcik go-librespot[20498]: time="2026-08-31T17:01:34+02:00" level=debug msg="completed keyexchange" Aug 31 17:01:34 bcik go-librespot[20498]: time="2026-08-31T17:01:34+02:00" level=debug msg="completed challenge" Aug 31 17:01:34 bcik go-librespot[20498]: time="2026-08-31T17:01:34+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 17:01:34 bcik go-librespot[20498]: time="2026-08-31T17:01:34+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 17:01:34 bcik volumio[19839]: info: Connection to go-librespot Websocket closed Aug 31 17:01:34 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 17:01:34 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 17:01:36 bcik volumio[19839]: info: Getting Spotify volume Aug 31 17:01:36 bcik volumio[19839]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 17:01:36 bcik volumio[19839]: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 17:01:36 bcik volumio[19839]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Aug 31 17:01:36 bcik volumio[19839]: errno: -111, Aug 31 17:01:36 bcik volumio[19839]: code: 'ECONNREFUSED', Aug 31 17:01:36 bcik volumio[19839]: syscall: 'connect', Aug 31 17:01:36 bcik volumio[19839]: address: '127.0.0.1', Aug 31 17:01:36 bcik volumio[19839]: port: 9879, Aug 31 17:01:36 bcik volumio[19839]: response: undefined Aug 31 17:01:36 bcik volumio[19839]: } Aug 31 17:01:36 bcik volumio[19839]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 17:01:36 bcik sudo[20536]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-31 17:00' Aug 31 17:01:36 bcik sudo[20536]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 17:01:36 bcik sudo[20536]: pam_unix(sudo:session): session closed for user root Aug 31 17:01:36 bcik volumio-remote-updater[962]: [2026-08-31 17:01:36] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Aug 31 17:01:36 bcik volumio-remote-updater[962]: [2026-08-31 17:01:36] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Aug 31 17:01:36 bcik volumio5-onboarding[6890]: time=2026-08-31T17:01:36.322+02:00 level=ERROR msg="failed reading message" error="websocket: close 1006 (abnormal closure): unexpected EOF" Aug 31 17:01:36 bcik volumio5-onboarding[6890]: time=2026-08-31T17:01:36.323+02:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Aug 31 17:01:36 bcik systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Aug 31 17:01:36 bcik systemd[1]: volumio.service: Failed with result 'exit-code'. Aug 31 17:01:36 bcik systemd[1]: volumio.service: Consumed 8.539s CPU time. Aug 31 17:01:36 bcik systemd[1]: Started dynamicswap.service - dynamicswap service. Aug 31 17:01:36 bcik systemd[1]: dynamicswap.service: Deactivated successfully. Aug 31 17:01:36 bcik systemd[1]: volumio.service: Scheduled restart job, restart counter is at 290. Aug 31 17:01:36 bcik systemd[1]: Started dynamicswap.service - dynamicswap service. Aug 31 17:01:36 bcik systemd[1]: Stopped volumio.service - Volumio Backend Module. Aug 31 17:01:36 bcik systemd[1]: volumio.service: Consumed 8.539s CPU time. Aug 31 17:01:36 bcik systemd[1]: Started volumio.service - Volumio Backend Module. Aug 31 17:01:36 bcik systemd[1]: dynamicswap.service: Deactivated successfully. Aug 31 17:01:36 bcik volumio[20549]: info: ------------------------------------------- Aug 31 17:01:36 bcik volumio[20549]: info: ----- Volumio3 ---- Aug 31 17:01:36 bcik volumio[20549]: info: ------------------------------------------- Aug 31 17:01:36 bcik volumio[20549]: info: ----- System startup ---- Aug 31 17:01:36 bcik volumio[20549]: info: ------------------------------------------- Aug 31 17:01:37 bcik volumio[20549]: info: MYVOLUMIO Environment detected Aug 31 17:01:37 bcik volumio[20549]: info: Plugin folders cleanup Aug 31 17:01:37 bcik volumio[20549]: info: Scanning into folder /volumio/app/plugins/ Aug 31 17:01:37 bcik volumio[20549]: info: Scanning category audio_interface Aug 31 17:01:37 bcik volumio[20549]: info: Scanning category miscellanea Aug 31 17:01:37 bcik volumio[20549]: info: Scanning category music_service Aug 31 17:01:37 bcik volumio[20549]: info: Scanning category plugins.json Aug 31 17:01:37 bcik volumio[20549]: info: Scanning category system_controller Aug 31 17:01:37 bcik volumio[20549]: info: Scanning category user_interface Aug 31 17:01:37 bcik volumio[20549]: info: Scanning into folder /data/plugins/ Aug 31 17:01:37 bcik volumio[20549]: info: Scanning category music_service Aug 31 17:01:37 bcik volumio[20549]: info: Plugin folders cleanup completed Aug 31 17:01:37 bcik volumio[20549]: info: ------------------------------------------- Aug 31 17:01:37 bcik volumio[20549]: info: ----- Core plugins startup ---- Aug 31 17:01:37 bcik volumio[20549]: info: ------------------------------------------- Aug 31 17:01:37 bcik volumio[20549]: info: Loading plugins from folder /volumio/app/plugins/ Aug 31 17:01:37 bcik volumio[20549]: info: Adding plugin upnp to MyMusic Plugins Aug 31 17:01:37 bcik volumio[20549]: info: Adding plugin airplay_emulation to MyMusic Plugins Aug 31 17:01:37 bcik volumio[20549]: info: Adding plugin upnp_browser to MyMusic Plugins Aug 31 17:01:37 bcik volumio[20549]: info: Loading plugins from folder /data/plugins/ Aug 31 17:01:37 bcik volumio[20549]: info: Loading plugin "system"... Aug 31 17:01:37 bcik volumio[20549]: info: Loading plugin "appearance"... Aug 31 17:01:37 bcik volumio[20549]: info: Loading plugin "network"... Aug 31 17:01:37 bcik volumio[20549]: info: Refreshing Cached IP Addresses Aug 31 17:01:37 bcik volumio[20549]: info: Loading plugin "services"... Aug 31 17:01:37 bcik volumio[20549]: info: Loading plugin "volumio5onboarding"... Aug 31 17:01:37 bcik sudo[20577]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 31 17:01:37 bcik sudo[20577]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 17:01:37 bcik sudo[20579]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 31 17:01:37 bcik sudo[20579]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 17:01:37 bcik sudo[20577]: pam_unix(sudo:session): session closed for user root Aug 31 17:01:37 bcik volumio[20549]: info: Loading plugin "alsa_controller"... Aug 31 17:01:37 bcik sudo[20579]: pam_unix(sudo:session): session closed for user root Aug 31 17:01:37 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 17:01:37 bcik volumio[20549]: info: Loading plugin "wizard"... Aug 31 17:01:37 bcik volumio[20549]: info: Loading plugin "networkfs"... Aug 31 17:01:37 bcik volumio[20549]: info: Starting Udev Watcher for removable devices Aug 31 17:01:37 bcik volumio[20549]: info: Ignoring mount for partition: boot Aug 31 17:01:37 bcik volumio[20549]: info: Ignoring mount for partition: volumio Aug 31 17:01:37 bcik volumio[20549]: info: Ignoring mount for partition: volumio_data Aug 31 17:01:37 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 17:01:37 bcik volumio[20549]: info: Loading plugin "volumio_command_line_client"... Aug 31 17:01:37 bcik volumio[20549]: info: Loading plugin "upnp"... Aug 31 17:01:37 bcik volumio[20549]: info: [1788188497306] Starting Upmpd Daemon Aug 31 17:01:37 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 17:01:37 bcik volumio[20549]: info: Loading plugin "my_music"... Aug 31 17:01:37 bcik volumio[20549]: info: Loading plugin "mpd"... Aug 31 17:01:37 bcik volumio[20549]: info: Loading plugin "upnp_browser"... Aug 31 17:01:37 bcik volumio[20549]: info: Starting UPNP Browser Aug 31 17:01:37 bcik volumio[20549]: info: Loading plugin "alarm-clock"... Aug 31 17:01:37 bcik volumio[20549]: info: Loading plugin "airplay_emulation"... Aug 31 17:01:37 bcik volumio[20549]: info: Starting Shairport Sync Aug 31 17:01:37 bcik volumio[20549]: info: Loading plugin "last_100"... Aug 31 17:01:37 bcik volumio[20549]: info: Loading plugin "webradio"... Aug 31 17:01:37 bcik volumio[20549]: info: Loading plugin "i2s_dacs"... Aug 31 17:01:37 bcik volumio[20549]: info: Loading plugin "volumiodiscovery"... Aug 31 17:01:37 bcik volumio[20549]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 31 17:01:37 bcik volumio[20549]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 17:01:37 bcik volumio[20549]: *** WARNING *** For more information see Aug 31 17:01:37 bcik volumio[20549]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 31 17:01:37 bcik volumio[20549]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 17:01:37 bcik volumio[20549]: *** WARNING *** For more information see Aug 31 17:01:37 bcik node[20549]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 31 17:01:37 bcik node[20549]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 17:01:37 bcik node[20549]: *** WARNING *** For more information see Aug 31 17:01:37 bcik node[20549]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 31 17:01:37 bcik node[20549]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 17:01:37 bcik node[20549]: *** WARNING *** For more information see Aug 31 17:01:37 bcik volumio[20549]: info: Applying required configuration parameters for plugin volumiodiscovery Aug 31 17:01:37 bcik volumio[20549]: info: Discovery: Started advertising with name: Bącik Aug 31 17:01:37 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 17:01:37 bcik volumio[20549]: info: Loading plugin "spop"... Aug 31 17:01:37 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 226. Aug 31 17:01:37 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:01:37 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:01:37 bcik go-librespot[20609]: go-librespot daemon starting... Aug 31 17:01:37 bcik go-librespot[20610]: time="2026-08-31T17:01:37+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 17:01:37 bcik go-librespot[20610]: time="2026-08-31T17:01:37+02:00" level=debug msg="app state loaded" Aug 31 17:01:37 bcik go-librespot[20610]: time="2026-08-31T17:01:37+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 17:01:37 bcik go-librespot[20610]: time="2026-08-31T17:01: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 17:01:37 bcik go-librespot[20610]: time="2026-08-31T17:01:37+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 17:01:37 bcik go-librespot[20610]: time="2026-08-31T17:01:37+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 17:01:37 bcik go-librespot[20610]: time="2026-08-31T17:01:37+02:00" level=info msg="zeroconf server listening on port 45945" Aug 31 17:01:37 bcik volumio[20549]: info: Loading plugin "outputs"... Aug 31 17:01:37 bcik volumio[20549]: info: Loading plugin "albumart"... Aug 31 17:01:37 bcik volumio[20549]: info: Plugin example_plugin is not enabled Aug 31 17:01:37 bcik volumio[20549]: info: Loading plugin "inputs"... Aug 31 17:01:37 bcik volumio[20549]: info: Loading plugin "updater_comm"... Aug 31 17:01:37 bcik volumio[20549]: info: Plugin mpdemulation is not enabled Aug 31 17:01:37 bcik volumio[20549]: info: Loading plugin "rest_api"... Aug 31 17:01:37 bcik volumio[20549]: info: Loading plugin "websocket"... Aug 31 17:01:37 bcik volumio[20549]: info: Starting Socket.io Server version 1.7.4 Aug 31 17:01:37 bcik volumio[20549]: info: Loading plugin "radio_browser"... Aug 31 17:01:37 bcik go-librespot[20610]: time="2026-08-31T17:01:37+02:00" level=debug msg="obtained new client token: AAGGKyytBjAsNmrpGutpAFWGSeFDBt0SbSjdZvavUVdz06WNdsuh8Cg21/UPEeJ8YH9AtvrYDmcilMXYRW8SCSASktxXZ1yUvWoaX45nnQkkUiKanwF+Gj9NgSeXD4lb7lcJuwQZTMTZ1qCA0hFYArnF6rga2KbXpSqkY9YUEZi+bEe5/1k5f24dGELTB20JKkZHcIINeAH7RMXKNaeQmXN4vJ1ESIDopIqTHK2tqwmSOzoEMYWjv+M=" Aug 31 17:01:37 bcik go-librespot[20610]: time="2026-08-31T17:01:37+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 17:01:38 bcik go-librespot[20610]: time="2026-08-31T17:01:38+02:00" level=debug msg="completed keyexchange" Aug 31 17:01:38 bcik go-librespot[20610]: time="2026-08-31T17:01:38+02:00" level=debug msg="completed challenge" Aug 31 17:01:38 bcik volumio[20619]: Forking 3 albumart workers Aug 31 17:01:38 bcik volumio[20549]: info: Loading i18n strings for locale pl Aug 31 17:01:38 bcik volumio[20549]: Updating browse sources language Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 17:01:38 bcik go-librespot[20610]: time="2026-08-31T17:01:38+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::initPlayerControls Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 17:01:38 bcik volumio[20549]: Express server listening on port 3000 Aug 31 17:01:38 bcik volumio[20549]: [Metrics] WebUI: 1s 289.86ms Aug 31 17:01:38 bcik volumio[20549]: info: CoreStateMachine::resetVolumioState Aug 31 17:01:38 bcik volumio[20549]: info: CoreStateMachine::getcurrentVolume Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::volumioRetrievevolume Aug 31 17:01:38 bcik volumio[20549]: info: Volumio Network Manager: Network status updated: 1 Aug 31 17:01:38 bcik volumio[20549]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Aug 31 17:01:38 bcik volumio[20549]: info: VolumeController:: Volume=53 Mute =false Aug 31 17:01:38 bcik volumio[20549]: info: CoreStateMachine::pushState Aug 31 17:01:38 bcik volumio[20549]: info: CorePlayQueue::getTrack 0 Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::volumioPushState Aug 31 17:01:38 bcik go-librespot[20610]: time="2026-08-31T17:01:38+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 17:01:38 bcik volumio[20549]: info: CoreStateMachine::updateTrackBlock Aug 31 17:01:38 bcik volumio[20549]: info: CorePlayQueue::getTrackBlock Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::volumioRetrievevolume Aug 31 17:01:38 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 17:01:38 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 17:01:38 bcik volumio[20549]: info: Reloading queue from file Aug 31 17:01:38 bcik volumio[20549]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Aug 31 17:01:38 bcik volumio[20549]: info: CoreStateMachine::setRepeat false single undefined Aug 31 17:01:38 bcik volumio[20549]: info: CoreStateMachine::pushState Aug 31 17:01:38 bcik volumio[20549]: info: CorePlayQueue::getTrack 0 Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::volumioPushState Aug 31 17:01:38 bcik volumio[20549]: info: CoreStateMachine::setRandom false Aug 31 17:01:38 bcik volumio[20549]: info: CoreStateMachine::pushState Aug 31 17:01:38 bcik volumio[20549]: info: CorePlayQueue::getTrack 0 Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::volumioPushState Aug 31 17:01:38 bcik volumio[20549]: info: Setting Device type: Raspberry PI Aug 31 17:01:38 bcik volumio[20549]: info: Completed loading Core Plugins Aug 31 17:01:38 bcik volumio[20549]: info: Preparing to generate the ALSA configuration file Aug 31 17:01:38 bcik volumio[20549]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Aug 31 17:01:38 bcik volumio[20549]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04171 Aug 31 17:01:38 bcik volumio[20549]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Aug 31 17:01:38 bcik volumio[20549]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Aug 31 17:01:38 bcik volumio[20549]: info: VolumeController:: Volume=53 Mute =false Aug 31 17:01:38 bcik volumio[20549]: info: CoreStateMachine::pushState Aug 31 17:01:38 bcik volumio[20549]: info: CorePlayQueue::getTrack 0 Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::volumioPushState Aug 31 17:01:38 bcik volumio[20549]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Aug 31 17:01:38 bcik volumio[20549]: info: Asound.conf file unchanged, so no further update is needed Aug 31 17:01:38 bcik volumio[20549]: info: Output device has changed, restarting MPD Aug 31 17:01:38 bcik volumio[20549]: info: Output device has changed, restarting Shairport Sync Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 17:01:38 bcik sudo[20674]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 31 17:01:38 bcik sudo[20674]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 17:01:38 bcik sudo[20676]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 31 17:01:38 bcik sudo[20676]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 17:01:38 bcik sudo[20674]: pam_unix(sudo:session): session closed for user root Aug 31 17:01:38 bcik volumio[20549]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 31 17:01:38 bcik volumio[20549]: info: ___________ START PLUGINS ___________ Aug 31 17:01:38 bcik systemd[1]: Stopping mpd.service - Music Player Daemon... Aug 31 17:01:38 bcik volumio[20549]: info: ControllerMpd::onStart: Initializing MPD Aug 31 17:01:38 bcik volumio[20549]: info: Creating MPD Configuration file Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 17:01:38 bcik volumio[20549]: info: [1788188498248] CoreMusicLibrary::Adding element Serwery Mediów Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 17:01:38 bcik volumio[20549]: info: UPNP Browser: Client initialized successfully Aug 31 17:01:38 bcik sudo[20686]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 17:01:38 bcik sudo[20686]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 17:01:38 bcik sudo[20686]: pam_unix(sudo:session): session closed for user root Aug 31 17:01:38 bcik systemd[1]: mpd.service: Deactivated successfully. Aug 31 17:01:38 bcik systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 31 17:01:38 bcik sudo[20688]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 31 17:01:38 bcik systemd[1]: mpd.socket: Deactivated successfully. Aug 31 17:01:38 bcik sudo[20688]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 17:01:38 bcik systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 31 17:01:38 bcik systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 31 17:01:38 bcik volumio[20549]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 17:01:38 bcik sudo[20684]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Aug 31 17:01:38 bcik sudo[20684]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 17:01:38 bcik volumio[20549]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 17:01:38 bcik volumio[20549]: info: [1788188498287] CoreMusicLibrary::Adding element Last_100 Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 17:01:38 bcik volumio[20549]: info: [1788188498287] CoreMusicLibrary::Adding element Webradio Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 17:01:38 bcik volumio[20549]: info: Initializing BBC Radios Aug 31 17:01:38 bcik systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 31 17:01:38 bcik systemd[1]: Starting mpd.service - Music Player Daemon... Aug 31 17:01:38 bcik sudo[20684]: pam_unix(sudo:session): session closed for user root Aug 31 17:01:38 bcik systemd[1]: mpd.service: Deactivated successfully. Aug 31 17:01:38 bcik systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 31 17:01:38 bcik systemd[1]: mpd.socket: Deactivated successfully. Aug 31 17:01:38 bcik systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 31 17:01:38 bcik systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 31 17:01:38 bcik systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 31 17:01:38 bcik systemd[1]: Starting mpd.service - Music Player Daemon... Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 17:01:38 bcik volumio[20549]: info: Creating Spotify config file Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:01:38 bcik sudo[20712]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 31 17:01:38 bcik sudo[20712]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 31 17:01:38 bcik sudo[20712]: pam_unix(sudo:session): session closed for user root Aug 31 17:01:38 bcik volumio[20631]: Starting albumart workers Aug 31 17:01:38 bcik volumio[20630]: Starting albumart workers Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 17:01:38 bcik volumio[20549]: info: [1788188498432] CoreMusicLibrary::Adding element Radio Browser Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 17:01:38 bcik volumio[20549]: Cannot find translation for source Radio Browser Aug 31 17:01:38 bcik volumio[20549]: info: Volumio Calling Home Aug 31 17:01:38 bcik volumio[20549]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Aug 31 17:01:38 bcik volumio[20549]: info: MPD Permissions set Aug 31 17:01:38 bcik volumio[20549]: info: MPD Permissions set Aug 31 17:01:38 bcik volumio[20549]: info: Spotify config file written Aug 31 17:01:38 bcik volumio[20549]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:01:38 bcik sudo[20724]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 31 17:01:38 bcik sudo[20724]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 17:01:38 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:01:38 bcik volumio[20629]: Starting albumart workers Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:01:38 bcik volumio[20549]: info: No need to fix Spotify hosts Aug 31 17:01:38 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:01:38 bcik go-librespot[20728]: go-librespot daemon starting... Aug 31 17:01:38 bcik sudo[20724]: pam_unix(sudo:session): session closed for user root Aug 31 17:01:38 bcik go-librespot[20738]: time="2026-08-31T17:01:38+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 17:01:38 bcik go-librespot[20738]: time="2026-08-31T17:01:38+02:00" level=debug msg="app state loaded" Aug 31 17:01:38 bcik go-librespot[20738]: time="2026-08-31T17:01:38+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 17:01:38 bcik volumio[20549]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:01:38 bcik volumio[20549]: info: Volumio called home Aug 31 17:01:38 bcik volumio[20549]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:01:38 bcik volumio[20549]: info: Starting Shairport Sync Aug 31 17:01:38 bcik volumio[20549]: info: Starting Shairport Sync Aug 31 17:01:38 bcik volumio[20549]: info: Starting Shairport Sync Aug 31 17:01:38 bcik sudo[20753]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 31 17:01:38 bcik sudo[20753]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 17:01:38 bcik sudo[20755]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 31 17:01:38 bcik sudo[20755]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 17:01:38 bcik sudo[20751]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 31 17:01:38 bcik sudo[20751]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 17:01:38 bcik systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 31 17:01:38 bcik systemd[1]: shairport-sync.service: Deactivated successfully. Aug 31 17:01:38 bcik systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 31 17:01:38 bcik systemd[1]: shairport-sync.service: Consumed 1.581s CPU time. Aug 31 17:01:38 bcik volumio[20549]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:01:38 bcik go-librespot[20738]: time="2026-08-31T17:01:38+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 17:01:38 bcik go-librespot[20738]: time="2026-08-31T17:01:38+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 17:01:38 bcik go-librespot[20738]: time="2026-08-31T17:01:38+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 17:01:38 bcik go-librespot[20738]: time="2026-08-31T17:01:38+02:00" level=info msg="zeroconf server listening on port 41329" Aug 31 17:01:38 bcik volumio[20549]: info: An error occurred while refreshing Spotify Token Error: Bad Request Aug 31 17:01:38 bcik volumio[20549]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:01:38 bcik systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 31 17:01:38 bcik sudo[20753]: pam_unix(sudo:session): session closed for user root Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::volumioGetState Aug 31 17:01:38 bcik volumio[20549]: info: CorePlayQueue::getTrack 0 Aug 31 17:01:38 bcik sudo[20755]: pam_unix(sudo:session): session closed for user root Aug 31 17:01:38 bcik sudo[20751]: pam_unix(sudo:session): session closed for user root Aug 31 17:01:38 bcik volumio[20549]: info: Discovery: adding f1ed5fb6-e21d-47c8-819b-29842600355e Aug 31 17:01:38 bcik volumio[20549]: info: Discovery: Found device Bącik Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::volumioGetState Aug 31 17:01:38 bcik volumio[20549]: info: CorePlayQueue::getTrack 0 Aug 31 17:01:38 bcik volumio[20549]: info: Discovery: this is already registered, f1ed5fb6-e21d-47c8-819b-29842600355e Aug 31 17:01:38 bcik volumio[20549]: info: Discovery: Found device Bącik Aug 31 17:01:38 bcik volumio[20549]: info: CoreCommandRouter::volumioGetState Aug 31 17:01:38 bcik volumio[20549]: info: CorePlayQueue::getTrack 0 Aug 31 17:01:38 bcik volumio[20549]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:01:38 bcik volumio[20549]: info: Shairport-Sync Started Aug 31 17:01:38 bcik go-librespot[20738]: time="2026-08-31T17:01:38+02:00" level=debug msg="obtained new client token: AAEDlOR3e1mnj5lj4MCrnS9CH9trWFeFRfJli19QAUMk/g4VAzIlzZ4KSE9HohseuJe8JCs6/nP3hTpRjgFs/vpJ0rp5NXwEwZ+G3kVFJ8FyLSj3L+r3h17H9dbwjMJR6thv5sILr1+52b/VWG7JBod9iYCfKVw2NBhm9RFMVmVIxWf0YKjPDmbFlekdBJQr6ar5gYXh1DDkmqBJmi8bnRLtw6R08OXi+2JTtJRsaov2dQ4Qjg0qakg=" Aug 31 17:01:38 bcik volumio[20549]: Error adding Membership: Error: addMembership EINVAL Aug 31 17:01:38 bcik volumio[20549]: info: Shairport-Sync Started Aug 31 17:01:38 bcik volumio[20549]: info: Shairport-Sync Started Aug 31 17:01:38 bcik volumio[20549]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:01:38 bcik volumio[20549]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:01:38 bcik go-librespot[20738]: time="2026-08-31T17:01:38+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 17:01:38 bcik volumio[20549]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:01:38 bcik volumio[20549]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:01:38 bcik volumio[20549]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:01:38 bcik volumio[20549]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:01:38 bcik volumio[20549]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:01:38 bcik volumio[20549]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:01:38 bcik volumio[20549]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:01:38 bcik volumio[20549]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:01:38 bcik volumio[20549]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:01:38 bcik volumio[20549]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:01:38 bcik volumio[20549]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:01:38 bcik volumio[20549]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:01:38 bcik volumio[20549]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:01:38 bcik volumio[20549]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:01:38 bcik volumio[20549]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:01:38 bcik volumio[20549]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:01:38 bcik volumio[20549]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:01:38 bcik volumio[20549]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:01:38 bcik go-librespot[20738]: time="2026-08-31T17:01:38+02:00" level=debug msg="completed keyexchange" Aug 31 17:01:38 bcik go-librespot[20738]: time="2026-08-31T17:01:38+02:00" level=debug msg="completed challenge" Aug 31 17:01:38 bcik go-librespot[20738]: time="2026-08-31T17:01:38+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 17:01:38 bcik mpd[20719]: 2026-08-31T17:01:38 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 31 17:01:38 bcik systemd[1]: Started mpd.service - Music Player Daemon. Aug 31 17:01:38 bcik sudo[20676]: pam_unix(sudo:session): session closed for user root Aug 31 17:01:38 bcik sudo[20688]: pam_unix(sudo:session): session closed for user root Aug 31 17:01:38 bcik volumio[20549]: error: updateQueue error: null Aug 31 17:01:38 bcik volumio[20549]: info: Completed starting Core Plugins Aug 31 17:01:38 bcik volumio[20549]: info: ------------------------------------------- Aug 31 17:01:38 bcik volumio[20549]: info: ----- MyVolumio plugins startup ---- Aug 31 17:01:38 bcik volumio[20549]: info: ------------------------------------------- Aug 31 17:01:38 bcik volumio[20549]: info: [MyVolumio PluginManager] Fetching plans data.... Aug 31 17:01:39 bcik volumio[20549]: error: updateQueue error: null Aug 31 17:01:39 bcik volumio[20549]: info: MPD running with PID20719 Aug 31 17:01:39 bcik volumio[20549]: ,establishing connection Aug 31 17:01:39 bcik go-librespot[20738]: time="2026-08-31T17:01:39+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 17:01:39 bcik volumio[20549]: error: updateQueue error: null Aug 31 17:01:39 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 17:01:39 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 17:01:41 bcik volumio-remote-updater[962]: [2026-08-31 17:01:41] [connect] Successful connection Aug 31 17:01:41 bcik volumio-remote-updater[962]: [2026-08-31 17:01:41] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1788188501 101 Aug 31 17:01:41 bcik volumio[20549]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 3 Aug 31 17:01:41 bcik volumio[20549]: info: go-librespot daemon successfully initialized Aug 31 17:01:42 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 227. Aug 31 17:01:42 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:01:42 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:01:42 bcik go-librespot[20796]: go-librespot daemon starting... Aug 31 17:01:42 bcik go-librespot[20797]: time="2026-08-31T17:01:42+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 17:01:42 bcik go-librespot[20797]: time="2026-08-31T17:01:42+02:00" level=debug msg="app state loaded" Aug 31 17:01:42 bcik go-librespot[20797]: time="2026-08-31T17:01:42+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 17:01:42 bcik go-librespot[20797]: time="2026-08-31T17:01: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 31 17:01:42 bcik go-librespot[20797]: time="2026-08-31T17:01:42+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 31 17:01:42 bcik go-librespot[20797]: time="2026-08-31T17:01:42+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 31 17:01:42 bcik go-librespot[20797]: time="2026-08-31T17:01:42+02:00" level=info msg="zeroconf server listening on port 45101" Aug 31 17:01:42 bcik go-librespot[20797]: time="2026-08-31T17:01:42+02:00" level=debug msg="obtained new client token: AAFuYlteOqt1vXa0BROHFiRY4QmZtBnFUpIZNz9ICk8gQI6uv2Hk4wo3eI1TzV12viBDpFQkkcNHIcRT1McVNgBc/fPdVxwYTdAJdFic/0qipOMX+cwxDbkU0Ms43Ih1FbUlZe208tHyn8q3/pvWnCVJU8pcgnVrOgJu+BuPe3X8e6Qd7j+XlOQgPbYsdEHJ2PS9E7VzpLS7lBOdCoOiTqIs9Jf+BzFuiTOQwGLrhLMhu63WswFOPXw=" Aug 31 17:01:42 bcik go-librespot[20797]: time="2026-08-31T17:01:42+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 17:01:42 bcik go-librespot[20797]: time="2026-08-31T17:01:42+02:00" level=debug msg="completed keyexchange" Aug 31 17:01:42 bcik go-librespot[20797]: time="2026-08-31T17:01:42+02:00" level=debug msg="completed challenge" Aug 31 17:01:42 bcik go-librespot[20797]: time="2026-08-31T17:01:42+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 17:01:42 bcik go-librespot[20797]: time="2026-08-31T17:01:42+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 17:01:42 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 17:01:42 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 17:01:43 bcik volumio[20549]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Aug 31 17:01:44 bcik volumio[20549]: info: Initializing connection to go-librespot Websocket Aug 31 17:01:44 bcik volumio[20549]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 17:01:45 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 228. Aug 31 17:01:45 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:01:45 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:01:45 bcik go-librespot[20808]: go-librespot daemon starting... Aug 31 17:01:45 bcik go-librespot[20809]: time="2026-08-31T17:01:45+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 17:01:45 bcik go-librespot[20809]: time="2026-08-31T17:01:45+02:00" level=debug msg="app state loaded" Aug 31 17:01:45 bcik go-librespot[20809]: time="2026-08-31T17:01:45+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 17:01:45 bcik go-librespot[20809]: time="2026-08-31T17:01: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 17:01:45 bcik go-librespot[20809]: time="2026-08-31T17:01:45+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 17:01:45 bcik go-librespot[20809]: time="2026-08-31T17:01:45+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 17:01:45 bcik go-librespot[20809]: time="2026-08-31T17:01:45+02:00" level=info msg="zeroconf server listening on port 37963" Aug 31 17:01:46 bcik go-librespot[20809]: time="2026-08-31T17:01:46+02:00" level=debug msg="obtained new client token: AAFBusLXw8SwXy895iilYg4JbE82oU3RunurzTjL0/CY6cCrZur+TX3JdH88A58Mj76fjlcD/rmROmLXq3XXTiOiQHYcKmioWL36EtvksIU0WRrK/1DSzU0GepTOc3Hs0WSu3t9tRD3UUZWPwU5wzxqHsBDqMAMRhSDa54UYzx2BnThiitRkHXQDQgVxQfuwatl+9sYM8xqMFaRpzjCo9i/8Ws3+qOJE/3wOonUioY8iTGQV5JRu/0g=" Aug 31 17:01:46 bcik go-librespot[20809]: time="2026-08-31T17:01:46+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 17:01:46 bcik go-librespot[20809]: time="2026-08-31T17:01:46+02:00" level=debug msg="completed keyexchange" Aug 31 17:01:46 bcik go-librespot[20809]: time="2026-08-31T17:01:46+02:00" level=debug msg="completed challenge" Aug 31 17:01:46 bcik go-librespot[20809]: time="2026-08-31T17:01:46+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 17:01:46 bcik go-librespot[20809]: time="2026-08-31T17:01:46+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 17:01:46 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 17:01:46 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 17:01:47 bcik sudo[20833]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 31 17:01:47 bcik sudo[20833]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 17:01:47 bcik sudo[20835]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 31 17:01:47 bcik sudo[20835]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 17:01:47 bcik sudo[20835]: pam_unix(sudo:session): session closed for user root Aug 31 17:01:47 bcik volumio[20549]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Aug 31 17:01:47 bcik volumio[20549]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Aug 31 17:01:47 bcik volumio[20549]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Aug 31 17:01:47 bcik volumio[20549]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Aug 31 17:01:47 bcik volumio[20549]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Aug 31 17:01:47 bcik volumio[20549]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Aug 31 17:01:47 bcik volumio[20549]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Aug 31 17:01:47 bcik volumio[20549]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Aug 31 17:01:47 bcik volumio[20549]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Aug 31 17:01:47 bcik volumio[20549]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Aug 31 17:01:47 bcik volumio[20549]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Aug 31 17:01:47 bcik volumio[20549]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Aug 31 17:01:47 bcik volumio[20549]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Aug 31 17:01:47 bcik volumio[20549]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Aug 31 17:01:47 bcik volumio[20549]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Aug 31 17:01:47 bcik volumio[20549]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Aug 31 17:01:47 bcik volumio[20549]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Aug 31 17:01:47 bcik volumio[20549]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Aug 31 17:01:47 bcik volumio[20549]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Aug 31 17:01:47 bcik volumio[20549]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Aug 31 17:01:47 bcik volumio[20549]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Aug 31 17:01:47 bcik volumio[20549]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Aug 31 17:01:47 bcik volumio[20549]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Aug 31 17:01:47 bcik volumio[20549]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Aug 31 17:01:47 bcik volumio[20549]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Aug 31 17:01:47 bcik volumio[20549]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Aug 31 17:01:47 bcik volumio[20549]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Aug 31 17:01:47 bcik sudo[20838]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Aug 31 17:01:47 bcik sudo[20833]: pam_unix(sudo:session): session closed for user root Aug 31 17:01:47 bcik volumio[20549]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Aug 31 17:01:47 bcik sudo[20838]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 17:01:47 bcik volumio[20549]: info: Adding plugin bluetooth to MyMusic Plugins Aug 31 17:01:47 bcik volumio[20549]: info: Adding plugin multiroom to MyMusic Plugins Aug 31 17:01:47 bcik volumio[20549]: info: Adding plugin metavolumio to MyMusic Plugins Aug 31 17:01:47 bcik volumio[20549]: info: Adding plugin cd_controller to MyMusic Plugins Aug 31 17:01:47 bcik volumio[20549]: info: Adding plugin qobuzconnect to MyMusic Plugins Aug 31 17:01:47 bcik volumio[20549]: info: Adding plugin smart_inputs to MyMusic Plugins Aug 31 17:01:47 bcik volumio[20549]: info: Adding plugin tidalconnect to MyMusic Plugins Aug 31 17:01:47 bcik volumio[20549]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Aug 31 17:01:47 bcik sudo[20838]: pam_unix(sudo:session): session closed for user root Aug 31 17:01:47 bcik volumio[20549]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Aug 31 17:01:47 bcik volumio[20549]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Aug 31 17:01:47 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 17:01:47 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 17:01:47 bcik volumio[20549]: info: Starting MyVolumio Remote Streaming Endpoints Aug 31 17:01:47 bcik volumio[20549]: info: MyVolumio login type: Token Aug 31 17:01:47 bcik volumio[20549]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Aug 31 17:01:47 bcik volumio[20549]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Aug 31 17:01:47 bcik volumio[20549]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Aug 31 17:01:47 bcik volumio[20549]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Aug 31 17:01:47 bcik volumio[20549]: info: Streaming services startup Aug 31 17:01:47 bcik volumio[20549]: info: Starting Streaming Daemon Aug 31 17:01:47 bcik sudo[20842]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 31 17:01:47 bcik volumio[20549]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Aug 31 17:01:47 bcik sudo[20842]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 17:01:47 bcik sudo[20842]: pam_unix(sudo:session): session closed for user root Aug 31 17:01:47 bcik volumio[20549]: info: Initializing connection to go-librespot Websocket Aug 31 17:01:47 bcik volumio[20549]: error: Cannot start Volumio Streaming Daemon Aug 31 17:01:47 bcik volumio[20549]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 31 17:01:47 bcik volumio[20549]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 31 17:01:47 bcik volumio[20549]: info: Upmpdcli Daemon Started Aug 31 17:01:47 bcik volumio[20549]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 17:01:48 bcik volumio[20549]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Aug 31 17:01:48 bcik volumio[20549]: info: MyVolumio token set successfully Aug 31 17:01:48 bcik volumio[20549]: info: MYVOLUMIO: Adding device Aug 31 17:01:48 bcik volumio[20549]: info: MYVOLUMIO: Evaluating Server Aug 31 17:01:48 bcik volumio[20549]: info: MyVolumio status changed Aug 31 17:01:48 bcik volumio[20549]: info: Streaming services startup Aug 31 17:01:48 bcik volumio[20549]: info: Starting Streaming Daemon Aug 31 17:01:48 bcik volumio[20549]: info: Removing browser output: myVolumio user plan is not superstar Aug 31 17:01:48 bcik volumio[20549]: info: Removing audio output: Aug 31 17:01:48 bcik volumio[20549]: info: Stoppping Tunnel 1 Aug 31 17:01:48 bcik sudo[20871]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 31 17:01:48 bcik sudo[20871]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 17:01:48 bcik sudo[20871]: pam_unix(sudo:session): session closed for user root Aug 31 17:01:48 bcik volumio[20549]: error: Cannot start Volumio Streaming Daemon Aug 31 17:01:48 bcik volumio[20549]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 31 17:01:48 bcik volumio[20549]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 31 17:01:48 bcik sudo[20874]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Aug 31 17:01:48 bcik sudo[20874]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 17:01:48 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 31 17:01:48 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 31 17:01:48 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 31 17:01:48 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 31 17:01:48 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 31 17:01:48 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 31 17:01:48 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 31 17:01:48 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 31 17:01:48 bcik sudo[20874]: pam_unix(sudo:session): session closed for user root Aug 31 17:01:48 bcik volumio[20549]: info: Remote SSH Stopped Aug 31 17:01:48 bcik nmbd[1285]: [2026/08/31 17:01:48.830149, 0] ../../source3/nmbd/nmbd_nameregister.c:73(register_name_response) Aug 31 17:01:48 bcik nmbd[1285]: register_name_response: Answer name <00> differs from question name <00>. Aug 31 17:01:48 bcik nmbd[1285]: [2026/08/31 17:01:48.830256, 0] ../../source3/nmbd/nmbd_nameregister.c:73(register_name_response) Aug 31 17:01:48 bcik nmbd[1285]: register_name_response: Answer name <03> differs from question name <03>. Aug 31 17:01:48 bcik nmbd[1285]: [2026/08/31 17:01:48.830314, 0] ../../source3/nmbd/nmbd_nameregister.c:73(register_name_response) Aug 31 17:01:48 bcik nmbd[1285]: register_name_response: Answer name <20> differs from question name <20>. Aug 31 17:01:49 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 229. Aug 31 17:01:49 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:01:49 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:01:49 bcik go-librespot[20876]: go-librespot daemon starting... Aug 31 17:01:49 bcik go-librespot[20877]: time="2026-08-31T17:01:49+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 17:01:49 bcik go-librespot[20877]: time="2026-08-31T17:01:49+02:00" level=debug msg="app state loaded" Aug 31 17:01:49 bcik go-librespot[20877]: time="2026-08-31T17:01:49+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 17:01:49 bcik go-librespot[20877]: time="2026-08-31T17:01:49+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 17:01:49 bcik go-librespot[20877]: time="2026-08-31T17:01:49+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 17:01:49 bcik go-librespot[20877]: time="2026-08-31T17:01:49+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 17:01:49 bcik go-librespot[20877]: time="2026-08-31T17:01:49+02:00" level=info msg="zeroconf server listening on port 35393" Aug 31 17:01:49 bcik go-librespot[20877]: time="2026-08-31T17:01:49+02:00" level=debug msg="obtained new client token: AAEOM4CuneQajk4h5YmRoYR8nGKsTfiBtKmJOyORDuPnHuqRmFGEfieyE5nRVOTonN8Z0zHjF/e4pVN7YCa5KLC9hraeFNf/lN5fn8Ea4Ii3mfaFJyUptpOXwOy79GyCr8oQ1LO561b/ytNtvRiKCO4hyvrrTG+KPFVoxZhrzQPTK7NHeiostDXuilyLweWvTxn2a2zcKgAzESMMUxD2p2qdsmCfNQfFlxcUIroHITX0n9c+yOBiaMc=" Aug 31 17:01:49 bcik go-librespot[20877]: time="2026-08-31T17:01:49+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 17:01:49 bcik go-librespot[20877]: time="2026-08-31T17:01:49+02:00" level=debug msg="completed keyexchange" Aug 31 17:01:49 bcik go-librespot[20877]: time="2026-08-31T17:01:49+02:00" level=debug msg="completed challenge" Aug 31 17:01:49 bcik go-librespot[20877]: time="2026-08-31T17:01:49+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 17:01:49 bcik go-librespot[20877]: time="2026-08-31T17:01:49+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 17:01:49 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 17:01:49 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 17:01:50 bcik volumio[20549]: info: Setting Geolocation for MyVolumio to eu7 Aug 31 17:01:50 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 17:01:50 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 17:01:50 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 17:01:50 bcik volumio[20549]: info: Initializing connection to go-librespot Websocket Aug 31 17:01:50 bcik volumio[20549]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 17:01:51 bcik volumio[20549]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Aug 31 17:01:51 bcik volumio[20549]: info: Updating MyVolumio device info Aug 31 17:01:51 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 17:01:51 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 17:01:51 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 17:01:52 bcik volumio[20549]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Aug 31 17:01:53 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 230. Aug 31 17:01:53 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:01:53 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:01:53 bcik go-librespot[20888]: go-librespot daemon starting... Aug 31 17:01:53 bcik go-librespot[20889]: time="2026-08-31T17:01:53+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 17:01:53 bcik go-librespot[20889]: time="2026-08-31T17:01:53+02:00" level=debug msg="app state loaded" Aug 31 17:01:53 bcik go-librespot[20889]: time="2026-08-31T17:01:53+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 17:01:53 bcik go-librespot[20889]: time="2026-08-31T17:01:53+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 17:01:53 bcik go-librespot[20889]: time="2026-08-31T17:01:53+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 17:01:53 bcik go-librespot[20889]: time="2026-08-31T17:01:53+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 17:01:53 bcik go-librespot[20889]: time="2026-08-31T17:01:53+02:00" level=info msg="zeroconf server listening on port 34745" Aug 31 17:01:53 bcik go-librespot[20889]: time="2026-08-31T17:01:53+02:00" level=debug msg="obtained new client token: AAGkTJbGcoN6qlAJwmX2B7zvxBGXe0G/2+y+4eKvnSUBA8DFdahOcKRGtGZRhnSiwkg61IYaLkEvRhgVdYr5J2pPOVFFnbsWD597kziUvShAma21XdomcoOvH4fSF+3MoSQupnIfk0sFL746HAkDs+vds1k0ENj7xTG+JPoF/NctsoX9wV0UPHOa1wP79IQkMAdwqqnFtFCRshuBxBAQQUyFM0/T7B5+IUHjuYLgiGxkmvMV2Xfh" Aug 31 17:01:53 bcik go-librespot[20889]: time="2026-08-31T17:01:53+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 17:01:53 bcik go-librespot[20889]: time="2026-08-31T17:01:53+02:00" level=debug msg="completed keyexchange" Aug 31 17:01:53 bcik go-librespot[20889]: time="2026-08-31T17:01:53+02:00" level=debug msg="completed challenge" Aug 31 17:01:53 bcik go-librespot[20889]: time="2026-08-31T17:01:53+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 17:01:53 bcik go-librespot[20889]: time="2026-08-31T17:01:53+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 17:01:53 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 17:01:53 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 17:01:53 bcik volumio[20549]: info: Initializing connection to go-librespot Websocket Aug 31 17:01:53 bcik volumio[20549]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 17:01:55 bcik volumio[20549]: info: MYVOLUMIO: Adding device Aug 31 17:01:55 bcik volumio[20549]: info: MYVOLUMIO: Evaluating Server Aug 31 17:01:56 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 231. Aug 31 17:01:56 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:01:56 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:01:56 bcik go-librespot[20916]: go-librespot daemon starting... Aug 31 17:01:56 bcik go-librespot[20917]: time="2026-08-31T17:01:56+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 17:01:56 bcik go-librespot[20917]: time="2026-08-31T17:01:56+02:00" level=debug msg="app state loaded" Aug 31 17:01:56 bcik go-librespot[20917]: time="2026-08-31T17:01:56+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 17:01:56 bcik go-librespot[20917]: time="2026-08-31T17:01:56+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 17:01:56 bcik go-librespot[20917]: time="2026-08-31T17:01:56+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 17:01:56 bcik go-librespot[20917]: time="2026-08-31T17:01:56+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 17:01:56 bcik go-librespot[20917]: time="2026-08-31T17:01:56+02:00" level=info msg="zeroconf server listening on port 46139" Aug 31 17:01:56 bcik go-librespot[20917]: time="2026-08-31T17:01:56+02:00" level=debug msg="obtained new client token: AAGGdNX2zE8XovWzxEG9s9SohlfM/MrfhAvLD7qmFg8QZd4Vd+0filrVF5b+N4/7dJF+4ei1v67//AyuqAF0ezv4NJyV91D6ZudJD7mWD94+S+2qf18vZdL5UVwsvQkrBLlRYANfIYVy9zB7Z/imqaKCQkU6vBlPonz4+3+q6+xoAqfnui+4g6PLfDeq85siexiiL64aLipICLfsX71lw60uhxlevtDHvKIEESF98MpWGrD8b9QSRZ4=" Aug 31 17:01:56 bcik go-librespot[20917]: time="2026-08-31T17:01:56+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 17:01:56 bcik volumio[20549]: info: Initializing connection to go-librespot Websocket Aug 31 17:01:56 bcik go-librespot[20917]: time="2026-08-31T17:01:56+02:00" level=debug msg="new websocket client" Aug 31 17:01:56 bcik volumio[20549]: info: Connection to go-librespot Websocket established Aug 31 17:01:56 bcik go-librespot[20917]: time="2026-08-31T17:01:56+02:00" level=debug msg="completed keyexchange" Aug 31 17:01:56 bcik go-librespot[20917]: time="2026-08-31T17:01:56+02:00" level=debug msg="completed challenge" Aug 31 17:01:56 bcik go-librespot[20917]: time="2026-08-31T17:01:56+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 17:01:56 bcik go-librespot[20917]: time="2026-08-31T17:01:56+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 17:01:56 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 17:01:56 bcik volumio[20549]: info: Connection to go-librespot Websocket closed Aug 31 17:01:56 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 17:01:57 bcik volumio[20549]: info: Setting Geolocation for MyVolumio to eu6 Aug 31 17:01:57 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 17:01:57 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 17:01:57 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 17:01:57 bcik volumio[20549]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Aug 31 17:01:58 bcik volumio[20549]: info: Updating MyVolumio device info Aug 31 17:01:58 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 17:01:58 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 17:01:58 bcik volumio[20549]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 17:01:58 bcik volumio[20549]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Aug 31 17:01:59 bcik volumio[20549]: info: Getting Spotify volume Aug 31 17:01:59 bcik volumio[20549]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 17:01:59 bcik volumio[20549]: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 17:01:59 bcik volumio[20549]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Aug 31 17:01:59 bcik volumio[20549]: errno: -111, Aug 31 17:01:59 bcik volumio[20549]: code: 'ECONNREFUSED', Aug 31 17:01:59 bcik volumio[20549]: syscall: 'connect', Aug 31 17:01:59 bcik volumio[20549]: address: '127.0.0.1', Aug 31 17:01:59 bcik volumio[20549]: port: 9879, Aug 31 17:01:59 bcik volumio[20549]: response: undefined Aug 31 17:01:59 bcik volumio[20549]: } Aug 31 17:01:59 bcik volumio[20549]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 17:01:59 bcik sudo[20954]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-31 17:00' Aug 31 17:01:59 bcik sudo[20954]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 17:01:59 bcik sudo[20954]: pam_unix(sudo:session): session closed for user root Aug 31 17:01:59 bcik volumio-remote-updater[962]: [2026-08-31 17:01:59] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Aug 31 17:01:59 bcik volumio-remote-updater[962]: [2026-08-31 17:01:59] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Aug 31 17:02:00 bcik volumio5-onboarding[6890]: time=2026-08-31T17:02:00.000+02:00 level=ERROR msg="failed reading message" error="websocket: close 1006 (abnormal closure): unexpected EOF" Aug 31 17:02:00 bcik systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Aug 31 17:02:00 bcik volumio5-onboarding[6890]: time=2026-08-31T17:02:00.000+02:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Aug 31 17:02:00 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 232. Aug 31 17:02:00 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:02:00 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:02:00 bcik go-librespot[20959]: go-librespot daemon starting... Aug 31 17:02:00 bcik systemd[1]: volumio.service: Failed with result 'exit-code'. Aug 31 17:02:00 bcik systemd[1]: volumio.service: Consumed 6.319s CPU time. Aug 31 17:02:00 bcik systemd[1]: Started dynamicswap.service - dynamicswap service. Aug 31 17:02:00 bcik go-librespot[20960]: time="2026-08-31T17:02:00+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 17:02:00 bcik go-librespot[20960]: time="2026-08-31T17:02:00+02:00" level=debug msg="app state loaded" Aug 31 17:02:00 bcik systemd[1]: dynamicswap.service: Deactivated successfully. Aug 31 17:02:00 bcik go-librespot[20960]: time="2026-08-31T17:02:00+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 17:02:00 bcik go-librespot[20960]: time="2026-08-31T17:02: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Aug 31 17:02:00 bcik go-librespot[20960]: time="2026-08-31T17:02:00+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 31 17:02:00 bcik go-librespot[20960]: time="2026-08-31T17:02:00+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 31 17:02:00 bcik go-librespot[20960]: time="2026-08-31T17:02:00+02:00" level=info msg="zeroconf server listening on port 42537" Aug 31 17:02:00 bcik systemd[1]: volumio.service: Scheduled restart job, restart counter is at 291. Aug 31 17:02:00 bcik systemd[1]: Started dynamicswap.service - dynamicswap service. Aug 31 17:02:00 bcik systemd[1]: Stopped volumio.service - Volumio Backend Module. Aug 31 17:02:00 bcik systemd[1]: volumio.service: Consumed 6.319s CPU time. Aug 31 17:02:00 bcik systemd[1]: Started volumio.service - Volumio Backend Module. Aug 31 17:02:00 bcik systemd[1]: dynamicswap.service: Deactivated successfully. Aug 31 17:02:00 bcik go-librespot[20960]: time="2026-08-31T17:02:00+02:00" level=debug msg="obtained new client token: AAEhBUmwl4KljPS9O7KI5kCfayjB/eSHyCWqvcc6jqE52/DzrNqwBTMuJ1uaPm4eY3TiQvFBzjTGOjMJac3Ednihv1UW5YWtrCTomRU3zjy/q6nL1hq27Q39a2zgIiTe2QVctfgoU3ceG8dToN45NsryU9L80U3GoIYsriahB5uhDBr3zazoMCrZA2DPw2Pp+4E7qt14TYW99IDWFJS5LeP0HidrEH12IcY3N3HR8G6JUotfmpiFAqI=" Aug 31 17:02:00 bcik go-librespot[20960]: time="2026-08-31T17:02:00+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 17:02:00 bcik go-librespot[20960]: time="2026-08-31T17:02:00+02:00" level=debug msg="completed keyexchange" Aug 31 17:02:00 bcik go-librespot[20960]: time="2026-08-31T17:02:00+02:00" level=debug msg="completed challenge" Aug 31 17:02:00 bcik volumio[20976]: info: ------------------------------------------- Aug 31 17:02:00 bcik volumio[20976]: info: ----- Volumio3 ---- Aug 31 17:02:00 bcik volumio[20976]: info: ------------------------------------------- Aug 31 17:02:00 bcik volumio[20976]: info: ----- System startup ---- Aug 31 17:02:00 bcik volumio[20976]: info: ------------------------------------------- Aug 31 17:02:00 bcik go-librespot[20960]: time="2026-08-31T17:02:00+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 17:02:00 bcik volumio[20976]: info: MYVOLUMIO Environment detected Aug 31 17:02:00 bcik go-librespot[20960]: time="2026-08-31T17:02:00+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 17:02:00 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 17:02:00 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 17:02:00 bcik volumio[20976]: info: Plugin folders cleanup Aug 31 17:02:00 bcik volumio[20976]: info: Scanning into folder /volumio/app/plugins/ Aug 31 17:02:00 bcik volumio[20976]: info: Scanning category audio_interface Aug 31 17:02:00 bcik volumio[20976]: info: Scanning category miscellanea Aug 31 17:02:00 bcik volumio[20976]: info: Scanning category music_service Aug 31 17:02:00 bcik volumio[20976]: info: Scanning category plugins.json Aug 31 17:02:00 bcik volumio[20976]: info: Scanning category system_controller Aug 31 17:02:00 bcik volumio[20976]: info: Scanning category user_interface Aug 31 17:02:00 bcik volumio[20976]: info: Scanning into folder /data/plugins/ Aug 31 17:02:00 bcik volumio[20976]: info: Scanning category music_service Aug 31 17:02:00 bcik volumio[20976]: info: Plugin folders cleanup completed Aug 31 17:02:00 bcik volumio[20976]: info: ------------------------------------------- Aug 31 17:02:00 bcik volumio[20976]: info: ----- Core plugins startup ---- Aug 31 17:02:00 bcik volumio[20976]: info: ------------------------------------------- Aug 31 17:02:00 bcik volumio[20976]: info: Loading plugins from folder /volumio/app/plugins/ Aug 31 17:02:00 bcik volumio[20976]: info: Adding plugin upnp to MyMusic Plugins Aug 31 17:02:00 bcik volumio[20976]: info: Adding plugin airplay_emulation to MyMusic Plugins Aug 31 17:02:00 bcik volumio[20976]: info: Adding plugin upnp_browser to MyMusic Plugins Aug 31 17:02:00 bcik volumio[20976]: info: Loading plugins from folder /data/plugins/ Aug 31 17:02:00 bcik volumio[20976]: info: Loading plugin "system"... Aug 31 17:02:00 bcik volumio[20976]: info: Loading plugin "appearance"... Aug 31 17:02:01 bcik volumio[20976]: info: Loading plugin "network"... Aug 31 17:02:01 bcik volumio[20976]: info: Refreshing Cached IP Addresses Aug 31 17:02:01 bcik volumio[20976]: info: Loading plugin "services"... Aug 31 17:02:01 bcik sudo[21004]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 31 17:02:01 bcik sudo[21004]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 17:02:01 bcik volumio[20976]: info: Loading plugin "volumio5onboarding"... Aug 31 17:02:01 bcik sudo[21006]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 31 17:02:01 bcik sudo[21006]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 17:02:01 bcik sudo[21004]: pam_unix(sudo:session): session closed for user root Aug 31 17:02:01 bcik sudo[21006]: pam_unix(sudo:session): session closed for user root Aug 31 17:02:01 bcik volumio[20976]: info: Loading plugin "alsa_controller"... Aug 31 17:02:01 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 17:02:01 bcik volumio[20976]: info: Loading plugin "wizard"... Aug 31 17:02:01 bcik volumio[20976]: info: Loading plugin "networkfs"... Aug 31 17:02:01 bcik volumio[20976]: info: Starting Udev Watcher for removable devices Aug 31 17:02:01 bcik volumio[20976]: info: Ignoring mount for partition: boot Aug 31 17:02:01 bcik volumio[20976]: info: Ignoring mount for partition: volumio Aug 31 17:02:01 bcik volumio[20976]: info: Ignoring mount for partition: volumio_data Aug 31 17:02:01 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 17:02:01 bcik volumio[20976]: info: Loading plugin "volumio_command_line_client"... Aug 31 17:02:01 bcik volumio[20976]: info: Loading plugin "upnp"... Aug 31 17:02:01 bcik volumio[20976]: info: [1788188521077] Starting Upmpd Daemon Aug 31 17:02:01 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 17:02:01 bcik volumio[20976]: info: Loading plugin "my_music"... Aug 31 17:02:01 bcik volumio[20976]: info: Loading plugin "mpd"... Aug 31 17:02:01 bcik volumio[20976]: info: Loading plugin "upnp_browser"... Aug 31 17:02:01 bcik volumio[20976]: info: Starting UPNP Browser Aug 31 17:02:01 bcik volumio[20976]: info: Loading plugin "alarm-clock"... Aug 31 17:02:01 bcik volumio[20976]: info: Loading plugin "airplay_emulation"... Aug 31 17:02:01 bcik volumio[20976]: info: Starting Shairport Sync Aug 31 17:02:01 bcik volumio[20976]: info: Loading plugin "last_100"... Aug 31 17:02:01 bcik volumio[20976]: info: Loading plugin "webradio"... Aug 31 17:02:01 bcik volumio[20976]: info: Loading plugin "i2s_dacs"... Aug 31 17:02:01 bcik volumio[20976]: info: Loading plugin "volumiodiscovery"... Aug 31 17:02:01 bcik volumio[20976]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 31 17:02:01 bcik volumio[20976]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 17:02:01 bcik volumio[20976]: *** WARNING *** For more information see Aug 31 17:02:01 bcik volumio[20976]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 31 17:02:01 bcik volumio[20976]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 17:02:01 bcik volumio[20976]: *** WARNING *** For more information see Aug 31 17:02:01 bcik node[20976]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 31 17:02:01 bcik node[20976]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 17:02:01 bcik node[20976]: *** WARNING *** For more information see Aug 31 17:02:01 bcik node[20976]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 31 17:02:01 bcik node[20976]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 17:02:01 bcik node[20976]: *** WARNING *** For more information see Aug 31 17:02:01 bcik volumio[20976]: info: Applying required configuration parameters for plugin volumiodiscovery Aug 31 17:02:01 bcik volumio[20976]: info: Discovery: Started advertising with name: Bącik Aug 31 17:02:01 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 17:02:01 bcik volumio[20976]: info: Loading plugin "spop"... Aug 31 17:02:01 bcik volumio[20976]: info: Loading plugin "outputs"... Aug 31 17:02:01 bcik volumio[20976]: info: Loading plugin "albumart"... Aug 31 17:02:01 bcik volumio[20976]: info: Plugin example_plugin is not enabled Aug 31 17:02:01 bcik volumio[20976]: info: Loading plugin "inputs"... Aug 31 17:02:01 bcik volumio[20976]: info: Loading plugin "updater_comm"... Aug 31 17:02:01 bcik volumio[20976]: info: Plugin mpdemulation is not enabled Aug 31 17:02:01 bcik volumio[20976]: info: Loading plugin "rest_api"... Aug 31 17:02:01 bcik volumio[20976]: info: Loading plugin "websocket"... Aug 31 17:02:01 bcik volumio[20976]: info: Starting Socket.io Server version 1.7.4 Aug 31 17:02:01 bcik volumio[20976]: info: Loading plugin "radio_browser"... Aug 31 17:02:01 bcik volumio[21036]: Forking 3 albumart workers Aug 31 17:02:01 bcik volumio[20976]: info: Loading i18n strings for locale pl Aug 31 17:02:01 bcik volumio[20976]: Updating browse sources language Aug 31 17:02:01 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 17:02:01 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 17:02:01 bcik volumio[20976]: info: CoreCommandRouter::initPlayerControls Aug 31 17:02:01 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:02:01 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:02:01 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:02:01 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:02:01 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:02:01 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:02:01 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:02:01 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:02:01 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 17:02:01 bcik volumio[20976]: Express server listening on port 3000 Aug 31 17:02:01 bcik volumio[20976]: [Metrics] WebUI: 1s 289.04ms Aug 31 17:02:01 bcik volumio[20976]: info: CoreStateMachine::resetVolumioState Aug 31 17:02:01 bcik volumio[20976]: info: CoreStateMachine::getcurrentVolume Aug 31 17:02:01 bcik volumio[20976]: info: CoreCommandRouter::volumioRetrievevolume Aug 31 17:02:01 bcik volumio[20976]: info: Volumio Network Manager: Network status updated: 1 Aug 31 17:02:01 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Aug 31 17:02:01 bcik volumio[20976]: info: VolumeController:: Volume=53 Mute =false Aug 31 17:02:01 bcik volumio[20976]: info: CoreStateMachine::pushState Aug 31 17:02:01 bcik volumio[20976]: info: CorePlayQueue::getTrack 0 Aug 31 17:02:01 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 17:02:01 bcik volumio[20976]: info: CoreCommandRouter::volumioPushState Aug 31 17:02:01 bcik volumio[20976]: info: CoreStateMachine::updateTrackBlock Aug 31 17:02:01 bcik volumio[20976]: info: CorePlayQueue::getTrackBlock Aug 31 17:02:01 bcik volumio[20976]: info: CoreCommandRouter::volumioRetrievevolume Aug 31 17:02:01 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 17:02:01 bcik volumio[20976]: info: Reloading queue from file Aug 31 17:02:01 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Aug 31 17:02:01 bcik volumio[20976]: info: CoreStateMachine::setRepeat false single undefined Aug 31 17:02:01 bcik volumio[20976]: info: CoreStateMachine::pushState Aug 31 17:02:01 bcik volumio[20976]: info: CorePlayQueue::getTrack 0 Aug 31 17:02:01 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 17:02:01 bcik volumio[20976]: info: CoreCommandRouter::volumioPushState Aug 31 17:02:01 bcik volumio[20976]: info: CoreStateMachine::setRandom false Aug 31 17:02:01 bcik volumio[20976]: info: CoreStateMachine::pushState Aug 31 17:02:01 bcik volumio[20976]: info: CorePlayQueue::getTrack 0 Aug 31 17:02:01 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 17:02:01 bcik volumio[20976]: info: CoreCommandRouter::volumioPushState Aug 31 17:02:01 bcik volumio[20976]: info: Setting Device type: Raspberry PI Aug 31 17:02:01 bcik volumio[20976]: info: Completed loading Core Plugins Aug 31 17:02:01 bcik volumio[20976]: info: Preparing to generate the ALSA configuration file Aug 31 17:02:02 bcik volumio[20976]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Aug 31 17:02:02 bcik volumio[20976]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04171 Aug 31 17:02:02 bcik volumio[20976]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Aug 31 17:02:02 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Aug 31 17:02:02 bcik volumio[20976]: info: VolumeController:: Volume=53 Mute =false Aug 31 17:02:02 bcik volumio[20976]: info: CoreStateMachine::pushState Aug 31 17:02:02 bcik volumio[20976]: info: CorePlayQueue::getTrack 0 Aug 31 17:02:02 bcik volumio[20976]: info: CoreCommandRouter::volumioPushState Aug 31 17:02:02 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Aug 31 17:02:02 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Aug 31 17:02:02 bcik volumio[20976]: info: Asound.conf file unchanged, so no further update is needed Aug 31 17:02:02 bcik volumio[20976]: info: Output device has changed, restarting MPD Aug 31 17:02:02 bcik sudo[21091]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 31 17:02:02 bcik sudo[21091]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 17:02:02 bcik volumio[20976]: info: Output device has changed, restarting Shairport Sync Aug 31 17:02:02 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:02:02 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 17:02:02 bcik sudo[21091]: pam_unix(sudo:session): session closed for user root Aug 31 17:02:02 bcik sudo[21093]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 31 17:02:02 bcik sudo[21093]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 17:02:02 bcik volumio[20976]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 31 17:02:02 bcik volumio[20976]: info: ___________ START PLUGINS ___________ Aug 31 17:02:02 bcik volumio[21047]: Starting albumart workers Aug 31 17:02:02 bcik systemd[1]: Stopping mpd.service - Music Player Daemon... Aug 31 17:02:02 bcik volumio[20976]: info: ControllerMpd::onStart: Initializing MPD Aug 31 17:02:02 bcik volumio[20976]: info: Creating MPD Configuration file Aug 31 17:02:02 bcik volumio[21046]: Starting albumart workers Aug 31 17:02:02 bcik sudo[21101]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Aug 31 17:02:02 bcik sudo[21101]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 17:02:02 bcik systemd[1]: mpd.service: Deactivated successfully. Aug 31 17:02:02 bcik systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 31 17:02:02 bcik systemd[1]: mpd.socket: Deactivated successfully. Aug 31 17:02:02 bcik systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 31 17:02:02 bcik systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 31 17:02:02 bcik sudo[21103]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 31 17:02:02 bcik sudo[21103]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 17:02:02 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 17:02:02 bcik volumio[20976]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 17:02:02 bcik volumio[20976]: info: [1788188522110] CoreMusicLibrary::Adding element Serwery Mediów Aug 31 17:02:02 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 17:02:02 bcik sudo[21106]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 31 17:02:02 bcik sudo[21106]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 17:02:02 bcik volumio[20976]: info: UPNP Browser: Client initialized successfully Aug 31 17:02:02 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:02:02 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 17:02:02 bcik volumio[21048]: Starting albumart workers Aug 31 17:02:02 bcik sudo[21103]: pam_unix(sudo:session): session closed for user root Aug 31 17:02:02 bcik volumio[20976]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 31 17:02:02 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:02:02 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 17:02:02 bcik systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 31 17:02:02 bcik systemd[1]: Starting mpd.service - Music Player Daemon... Aug 31 17:02:02 bcik volumio[20976]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 31 17:02:02 bcik volumio[20976]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 17:02:02 bcik volumio[20976]: info: [1788188522148] CoreMusicLibrary::Adding element Last_100 Aug 31 17:02:02 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 17:02:02 bcik volumio[20976]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 17:02:02 bcik volumio[20976]: info: [1788188522149] CoreMusicLibrary::Adding element Webradio Aug 31 17:02:02 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 17:02:02 bcik systemd[1]: mpd.service: Deactivated successfully. Aug 31 17:02:02 bcik systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 31 17:02:02 bcik systemd[1]: mpd.socket: Deactivated successfully. Aug 31 17:02:02 bcik systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 31 17:02:02 bcik systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 31 17:02:02 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 17:02:02 bcik volumio[20976]: info: Initializing BBC Radios Aug 31 17:02:02 bcik systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 31 17:02:02 bcik systemd[1]: Starting mpd.service - Music Player Daemon... Aug 31 17:02:02 bcik sudo[21101]: pam_unix(sudo:session): session closed for user root Aug 31 17:02:02 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 17:02:02 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 17:02:02 bcik volumio[20976]: info: Creating Spotify config file Aug 31 17:02:02 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:02:02 bcik sudo[21122]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 31 17:02:02 bcik sudo[21122]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 31 17:02:02 bcik sudo[21122]: pam_unix(sudo:session): session closed for user root Aug 31 17:02:02 bcik volumio[20976]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 17:02:02 bcik volumio[20976]: info: [1788188522318] CoreMusicLibrary::Adding element Radio Browser Aug 31 17:02:02 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 17:02:02 bcik volumio[20976]: Cannot find translation for source Radio Browser Aug 31 17:02:02 bcik volumio[20976]: info: Volumio Calling Home Aug 31 17:02:02 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Aug 31 17:02:02 bcik volumio[20976]: info: MPD Permissions set Aug 31 17:02:02 bcik volumio[20976]: info: MPD Permissions set Aug 31 17:02:02 bcik volumio[20976]: info: Spotify config file written Aug 31 17:02:02 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Aug 31 17:02:02 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:02:02 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:02:02 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:02:02 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:02:02 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:02:02 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:02:02 bcik sudo[21158]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 31 17:02:02 bcik sudo[21158]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 17:02:02 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:02:02 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:02:02 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 17:02:02 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:02:02 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:02:02 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:02:02 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:02:02 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:02:02 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:02:02 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:02:02 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:02:02 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:02:02 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:02:02 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 17:02:02 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:02:02 bcik volumio[20976]: info: No need to fix Spotify hosts Aug 31 17:02:02 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:02:02 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:02:02 bcik go-librespot[21170]: go-librespot daemon starting... Aug 31 17:02:02 bcik sudo[21158]: pam_unix(sudo:session): session closed for user root Aug 31 17:02:02 bcik go-librespot[21171]: time="2026-08-31T17:02:02+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 17:02:02 bcik go-librespot[21171]: time="2026-08-31T17:02:02+02:00" level=debug msg="app state loaded" Aug 31 17:02:02 bcik go-librespot[21171]: time="2026-08-31T17:02:02+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 17:02:02 bcik volumio[20976]: info: Volumio called home Aug 31 17:02:02 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:02:02 bcik volumio[20976]: info: Starting Shairport Sync Aug 31 17:02:02 bcik volumio[20976]: info: Starting Shairport Sync Aug 31 17:02:02 bcik volumio[20976]: info: Starting Shairport Sync Aug 31 17:02:02 bcik sudo[21178]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 31 17:02:02 bcik sudo[21182]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 31 17:02:02 bcik sudo[21178]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 17:02:02 bcik sudo[21182]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 17:02:02 bcik sudo[21180]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 31 17:02:02 bcik sudo[21180]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 17:02:02 bcik systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 31 17:02:02 bcik systemd[1]: shairport-sync.service: Deactivated successfully. Aug 31 17:02:02 bcik systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 31 17:02:02 bcik systemd[1]: shairport-sync.service: Consumed 1.505s CPU time. Aug 31 17:02:02 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:02:02 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:02:02 bcik volumio[20976]: info: Discovery: adding f1ed5fb6-e21d-47c8-819b-29842600355e Aug 31 17:02:02 bcik volumio[20976]: info: Discovery: Found device Bącik Aug 31 17:02:02 bcik volumio[20976]: info: CoreCommandRouter::volumioGetState Aug 31 17:02:02 bcik volumio[20976]: info: CorePlayQueue::getTrack 0 Aug 31 17:02:02 bcik systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 31 17:02:02 bcik sudo[21180]: pam_unix(sudo:session): session closed for user root Aug 31 17:02:02 bcik sudo[21182]: pam_unix(sudo:session): session closed for user root Aug 31 17:02:02 bcik volumio[20976]: info: CoreCommandRouter::volumioGetState Aug 31 17:02:02 bcik volumio[20976]: info: CorePlayQueue::getTrack 0 Aug 31 17:02:02 bcik sudo[21178]: pam_unix(sudo:session): session closed for user root Aug 31 17:02:02 bcik volumio[20976]: info: Discovery: this is already registered, f1ed5fb6-e21d-47c8-819b-29842600355e Aug 31 17:02:02 bcik volumio[20976]: info: Discovery: Found device Bącik Aug 31 17:02:02 bcik volumio[20976]: info: CoreCommandRouter::volumioGetState Aug 31 17:02:02 bcik volumio[20976]: info: CorePlayQueue::getTrack 0 Aug 31 17:02:02 bcik volumio[20976]: info: Shairport-Sync Started Aug 31 17:02:02 bcik volumio[20976]: Error adding Membership: Error: addMembership EINVAL Aug 31 17:02:02 bcik volumio[20976]: info: Shairport-Sync Started Aug 31 17:02:02 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:02:02 bcik volumio[20976]: info: Shairport-Sync Started Aug 31 17:02:02 bcik volumio[20976]: info: An error occurred while refreshing Spotify Token Error: Bad Request Aug 31 17:02:02 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:02:02 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:02:02 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:02:02 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:02:02 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:02:02 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:02:02 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:02:02 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:02:02 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:02:02 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:02:02 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:02:02 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:02:02 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:02:02 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:02:02 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:02:02 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:02:02 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:02:02 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:02:02 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:02:02 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:02:02 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:02:02 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:02:02 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:02:02 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:02:02 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:02:02 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:02:02 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:02:02 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:02:02 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:02:02 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:02:02 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:02:02 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:02:02 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:02:02 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 31 17:02:02 bcik go-librespot[21171]: time="2026-08-31T17:02:02+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 17:02:02 bcik go-librespot[21171]: time="2026-08-31T17:02:02+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 17:02:02 bcik go-librespot[21171]: time="2026-08-31T17:02:02+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 17:02:02 bcik go-librespot[21171]: time="2026-08-31T17:02:02+02:00" level=info msg="zeroconf server listening on port 35007" Aug 31 17:02:02 bcik go-librespot[21171]: time="2026-08-31T17:02:02+02:00" level=debug msg="obtained new client token: AAGuQWIYmGp0TrmzXjDLnRP3TsHGiXv//FAAg9Q4e+svBt2davZQQuo69+Po+zLw1EuufccWb3dhb6accZyabbY12a/WxJoUchXWyHlu20zCqQrizt4kxaxDQyVxXBU2eAyXh7PW7473psoE51z5qBx8L/vBHUlQsH4qZLnC3Z/TDsVqZ7dLWeJcRVnni8msfZlT+9vNlyH6Pf9mYIQ6GqpcwXWxa4BxcypSvpRBvtsm3UEj1H+yX+Y=" Aug 31 17:02:02 bcik go-librespot[21171]: time="2026-08-31T17:02:02+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 17:02:02 bcik mpd[21135]: 2026-08-31T17:02:02 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 31 17:02:02 bcik systemd[1]: Started mpd.service - Music Player Daemon. Aug 31 17:02:02 bcik sudo[21093]: pam_unix(sudo:session): session closed for user root Aug 31 17:02:02 bcik sudo[21106]: pam_unix(sudo:session): session closed for user root Aug 31 17:02:02 bcik volumio[20976]: info: Completed starting Core Plugins Aug 31 17:02:02 bcik volumio[20976]: info: ------------------------------------------- Aug 31 17:02:02 bcik volumio[20976]: info: ----- MyVolumio plugins startup ---- Aug 31 17:02:02 bcik volumio[20976]: info: ------------------------------------------- Aug 31 17:02:02 bcik volumio[20976]: info: [MyVolumio PluginManager] Fetching plans data.... Aug 31 17:02:02 bcik go-librespot[21171]: time="2026-08-31T17:02:02+02:00" level=debug msg="completed keyexchange" Aug 31 17:02:02 bcik go-librespot[21171]: time="2026-08-31T17:02:02+02:00" level=debug msg="completed challenge" Aug 31 17:02:02 bcik volumio[20976]: error: MPD error: The expression evaluated to a falsy value: Aug 31 17:02:02 bcik volumio[20976]: assert.ok(self.idling) Aug 31 17:02:02 bcik volumio[20976]: error: The expression evaluated to a falsy value: Aug 31 17:02:02 bcik volumio[20976]: assert.ok(self.idling) Aug 31 17:02:02 bcik volumio[20976]: info: MPD running with PID21135 Aug 31 17:02:02 bcik volumio[20976]: ,establishing connection Aug 31 17:02:02 bcik volumio[20976]: error: updateQueue error: null Aug 31 17:02:02 bcik volumio[20976]: error: updateQueue error: null Aug 31 17:02:02 bcik go-librespot[21171]: time="2026-08-31T17:02:02+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 17:02:02 bcik go-librespot[21171]: time="2026-08-31T17:02:02+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 17:02:02 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 17:02:02 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 17:02:04 bcik volumio-remote-updater[962]: [2026-08-31 17:02:04] [connect] Successful connection Aug 31 17:02:05 bcik volumio-remote-updater[962]: [2026-08-31 17:02:04] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1788188524 101 Aug 31 17:02:05 bcik volumio[20976]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 3 Aug 31 17:02:05 bcik volumio[20976]: info: go-librespot daemon successfully initialized Aug 31 17:02:06 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 233. Aug 31 17:02:06 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:02:06 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:02:06 bcik go-librespot[21213]: go-librespot daemon starting... Aug 31 17:02:06 bcik go-librespot[21214]: time="2026-08-31T17:02:06+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 17:02:06 bcik go-librespot[21214]: time="2026-08-31T17:02:06+02:00" level=debug msg="app state loaded" Aug 31 17:02:06 bcik go-librespot[21214]: time="2026-08-31T17:02:06+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 17:02:06 bcik go-librespot[21214]: time="2026-08-31T17:02: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-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 17:02:06 bcik go-librespot[21214]: time="2026-08-31T17:02:06+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 17:02:06 bcik go-librespot[21214]: time="2026-08-31T17:02:06+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 17:02:06 bcik go-librespot[21214]: time="2026-08-31T17:02:06+02:00" level=info msg="zeroconf server listening on port 34901" Aug 31 17:02:06 bcik go-librespot[21214]: time="2026-08-31T17:02:06+02:00" level=debug msg="obtained new client token: AAHe1I/i2sAbbRAjabk480xwB4HCQF/fCZoaFTvE7ciB0uKjLI+0QPw7058Mrl7IpHne3+zi+ObHNOvn2gC8fr0V028Al2pyuracHCHSX3/KDYMd88Tpuxk763GnyEY0DSCAjJ89C9WA0XQgOKtkpj57XZZyA1RctbiNOS4ivN0ukh8p2hjtJ3YxyczgD3Z+kO8erlfF9qlgksLttTXiJY9XZRux5cqP5uWX67R7NT2GLWqPgYIP" Aug 31 17:02:06 bcik go-librespot[21214]: time="2026-08-31T17:02:06+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 17:02:06 bcik go-librespot[21214]: time="2026-08-31T17:02:06+02:00" level=debug msg="completed keyexchange" Aug 31 17:02:06 bcik go-librespot[21214]: time="2026-08-31T17:02:06+02:00" level=debug msg="completed challenge" Aug 31 17:02:06 bcik go-librespot[21214]: time="2026-08-31T17:02:06+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 17:02:06 bcik go-librespot[21214]: time="2026-08-31T17:02:06+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 17:02:06 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 17:02:06 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 17:02:07 bcik volumio[20976]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Aug 31 17:02:08 bcik volumio[20976]: info: Initializing connection to go-librespot Websocket Aug 31 17:02:08 bcik volumio[20976]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 17:02:09 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 234. Aug 31 17:02:09 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:02:09 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:02:09 bcik go-librespot[21225]: go-librespot daemon starting... Aug 31 17:02:09 bcik go-librespot[21226]: time="2026-08-31T17:02:09+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 17:02:09 bcik go-librespot[21226]: time="2026-08-31T17:02:09+02:00" level=debug msg="app state loaded" Aug 31 17:02:09 bcik go-librespot[21226]: time="2026-08-31T17:02:09+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 17:02:09 bcik go-librespot[21226]: time="2026-08-31T17:02:09+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 17:02:09 bcik go-librespot[21226]: time="2026-08-31T17:02:09+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 17:02:09 bcik go-librespot[21226]: time="2026-08-31T17:02:09+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 17:02:09 bcik go-librespot[21226]: time="2026-08-31T17:02:09+02:00" level=info msg="zeroconf server listening on port 44143" Aug 31 17:02:09 bcik go-librespot[21226]: time="2026-08-31T17:02:09+02:00" level=debug msg="obtained new client token: AAHIBcMpCdyYF35uUa+0bWoKmFgoMkxpHZQPO6ro1y2Z9k3ffi/KnBpVoWPFHsvEBbJAM44ObMM3i4dd1zab0QLHEza7bUa0BNzvu5ph5a2NCdcoRqA4Wg1aoohqGXXQllRtEDwxcVj5z9I5WgxJBF/66JodPb19+MHzvRDkYL92jMCHu39eKvx//PWI8xzj3SuC5ktaDdsNkNKhE1gKulkyqa2rV1i2+bQWAONNEUZkxV1MuZlZLbs=" Aug 31 17:02:09 bcik go-librespot[21226]: time="2026-08-31T17:02:09+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 17:02:09 bcik go-librespot[21226]: time="2026-08-31T17:02:09+02:00" level=debug msg="completed keyexchange" Aug 31 17:02:09 bcik go-librespot[21226]: time="2026-08-31T17:02:09+02:00" level=debug msg="completed challenge" Aug 31 17:02:09 bcik go-librespot[21226]: time="2026-08-31T17:02:09+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 17:02:09 bcik go-librespot[21226]: time="2026-08-31T17:02:09+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 17:02:09 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 17:02:09 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 17:02:10 bcik volumio[20976]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Aug 31 17:02:10 bcik volumio[20976]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Aug 31 17:02:10 bcik volumio[20976]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Aug 31 17:02:10 bcik volumio[20976]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Aug 31 17:02:10 bcik volumio[20976]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Aug 31 17:02:10 bcik volumio[20976]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Aug 31 17:02:10 bcik volumio[20976]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Aug 31 17:02:10 bcik volumio[20976]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Aug 31 17:02:10 bcik volumio[20976]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Aug 31 17:02:10 bcik volumio[20976]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Aug 31 17:02:10 bcik volumio[20976]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Aug 31 17:02:10 bcik volumio[20976]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Aug 31 17:02:10 bcik volumio[20976]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Aug 31 17:02:10 bcik volumio[20976]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Aug 31 17:02:10 bcik volumio[20976]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Aug 31 17:02:10 bcik volumio[20976]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Aug 31 17:02:10 bcik volumio[20976]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Aug 31 17:02:10 bcik volumio[20976]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Aug 31 17:02:10 bcik volumio[20976]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Aug 31 17:02:10 bcik volumio[20976]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Aug 31 17:02:10 bcik volumio[20976]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Aug 31 17:02:10 bcik volumio[20976]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Aug 31 17:02:10 bcik volumio[20976]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Aug 31 17:02:10 bcik volumio[20976]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Aug 31 17:02:10 bcik volumio[20976]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Aug 31 17:02:10 bcik volumio[20976]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Aug 31 17:02:10 bcik volumio[20976]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Aug 31 17:02:10 bcik volumio[20976]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Aug 31 17:02:10 bcik volumio[20976]: info: Adding plugin bluetooth to MyMusic Plugins Aug 31 17:02:10 bcik volumio[20976]: info: Adding plugin multiroom to MyMusic Plugins Aug 31 17:02:10 bcik volumio[20976]: info: Adding plugin metavolumio to MyMusic Plugins Aug 31 17:02:10 bcik volumio[20976]: info: Adding plugin cd_controller to MyMusic Plugins Aug 31 17:02:10 bcik volumio[20976]: info: Adding plugin qobuzconnect to MyMusic Plugins Aug 31 17:02:10 bcik volumio[20976]: info: Adding plugin smart_inputs to MyMusic Plugins Aug 31 17:02:10 bcik volumio[20976]: info: Adding plugin tidalconnect to MyMusic Plugins Aug 31 17:02:10 bcik volumio[20976]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Aug 31 17:02:11 bcik volumio[20976]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Aug 31 17:02:11 bcik volumio[20976]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Aug 31 17:02:11 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 17:02:11 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 17:02:11 bcik volumio[20976]: info: Starting MyVolumio Remote Streaming Endpoints Aug 31 17:02:11 bcik volumio[20976]: info: MyVolumio login type: Token Aug 31 17:02:11 bcik volumio[20976]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Aug 31 17:02:11 bcik volumio[20976]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Aug 31 17:02:11 bcik volumio[20976]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Aug 31 17:02:11 bcik volumio[20976]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Aug 31 17:02:11 bcik volumio[20976]: info: Streaming services startup Aug 31 17:02:11 bcik volumio[20976]: info: Starting Streaming Daemon Aug 31 17:02:11 bcik sudo[21250]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 31 17:02:11 bcik sudo[21250]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 17:02:11 bcik volumio[20976]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Aug 31 17:02:11 bcik sudo[21250]: pam_unix(sudo:session): session closed for user root Aug 31 17:02:11 bcik sudo[21257]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 31 17:02:11 bcik sudo[21257]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 17:02:11 bcik volumio[20976]: error: Cannot start Volumio Streaming Daemon Aug 31 17:02:11 bcik volumio[20976]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 31 17:02:11 bcik volumio[20976]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 31 17:02:11 bcik sudo[21257]: pam_unix(sudo:session): session closed for user root Aug 31 17:02:11 bcik sudo[21259]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 31 17:02:11 bcik sudo[21259]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 17:02:11 bcik sudo[21259]: pam_unix(sudo:session): session closed for user root Aug 31 17:02:11 bcik sudo[21263]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Aug 31 17:02:11 bcik sudo[21263]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 17:02:11 bcik sudo[21263]: pam_unix(sudo:session): session closed for user root Aug 31 17:02:11 bcik volumio[20976]: info: Upmpdcli Daemon Started Aug 31 17:02:11 bcik volumio[20976]: info: Initializing connection to go-librespot Websocket Aug 31 17:02:11 bcik volumio[20976]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 17:02:11 bcik volumio[20976]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Aug 31 17:02:12 bcik volumio[20976]: info: MyVolumio token set successfully Aug 31 17:02:12 bcik volumio[20976]: info: MYVOLUMIO: Adding device Aug 31 17:02:12 bcik volumio[20976]: info: MYVOLUMIO: Evaluating Server Aug 31 17:02:12 bcik volumio[20976]: info: MyVolumio status changed Aug 31 17:02:12 bcik volumio[20976]: info: Streaming services startup Aug 31 17:02:12 bcik volumio[20976]: info: Starting Streaming Daemon Aug 31 17:02:12 bcik volumio[20976]: info: Removing browser output: myVolumio user plan is not superstar Aug 31 17:02:12 bcik volumio[20976]: info: Removing audio output: Aug 31 17:02:12 bcik volumio[20976]: info: Stoppping Tunnel 1 Aug 31 17:02:12 bcik sudo[21287]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 31 17:02:12 bcik sudo[21287]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 17:02:12 bcik sudo[21289]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Aug 31 17:02:12 bcik sudo[21289]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 17:02:12 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 31 17:02:12 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 31 17:02:12 bcik sudo[21287]: pam_unix(sudo:session): session closed for user root Aug 31 17:02:12 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 31 17:02:12 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 31 17:02:12 bcik volumio[20976]: error: Cannot start Volumio Streaming Daemon Aug 31 17:02:12 bcik volumio[20976]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 31 17:02:12 bcik volumio[20976]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 31 17:02:12 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 31 17:02:12 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 31 17:02:12 bcik sudo[21289]: pam_unix(sudo:session): session closed for user root Aug 31 17:02:12 bcik volumio[20976]: info: Remote SSH Stopped Aug 31 17:02:13 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 235. Aug 31 17:02:13 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:02:13 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:02:13 bcik go-librespot[21292]: go-librespot daemon starting... Aug 31 17:02:13 bcik go-librespot[21293]: time="2026-08-31T17:02:13+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 17:02:13 bcik go-librespot[21293]: time="2026-08-31T17:02:13+02:00" level=debug msg="app state loaded" Aug 31 17:02:13 bcik go-librespot[21293]: time="2026-08-31T17:02:13+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 17:02:13 bcik volumio[20976]: info: Setting Geolocation for MyVolumio to eu6 Aug 31 17:02:13 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 17:02:13 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 17:02:13 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 17:02:13 bcik go-librespot[21293]: time="2026-08-31T17:02: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-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 17:02:13 bcik go-librespot[21293]: time="2026-08-31T17:02:13+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 17:02:13 bcik go-librespot[21293]: time="2026-08-31T17:02:13+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 17:02:13 bcik go-librespot[21293]: time="2026-08-31T17:02:13+02:00" level=info msg="zeroconf server listening on port 46623" Aug 31 17:02:13 bcik go-librespot[21293]: time="2026-08-31T17:02:13+02:00" level=debug msg="obtained new client token: AAGVcSrMS9r4qpBKBB7qoBWp5Z9Y6SMPsR2FuKpaEjtHyfYz8bLR9TGmDR99nQiuAQ9OLW7voOWkizA1InvIZLjrXgSexSBxfHHi8vZhtKsIkm98dqVInNELE9Y25i0lnJwD8c1Yl+4Bl1sKeOHESKbuEv2DH2xLdpzQgZ14ie8WZ6HONFDDpPOkgctntFcKkLxoz+JTnXwq9ajGQzI3slzPis1xNheyQ7Og4H++ODCUPo67eVGQOtk=" Aug 31 17:02:13 bcik go-librespot[21293]: time="2026-08-31T17:02:13+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 17:02:13 bcik go-librespot[21293]: time="2026-08-31T17:02:13+02:00" level=debug msg="completed keyexchange" Aug 31 17:02:13 bcik go-librespot[21293]: time="2026-08-31T17:02:13+02:00" level=debug msg="completed challenge" Aug 31 17:02:13 bcik go-librespot[21293]: time="2026-08-31T17:02:13+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 17:02:13 bcik go-librespot[21293]: time="2026-08-31T17:02:13+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 17:02:13 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 17:02:13 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 17:02:13 bcik volumio[20976]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Aug 31 17:02:14 bcik volumio[20976]: info: Updating MyVolumio device info Aug 31 17:02:14 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 17:02:14 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 17:02:14 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 17:02:14 bcik volumio[20976]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Aug 31 17:02:14 bcik volumio[20976]: info: Initializing connection to go-librespot Websocket Aug 31 17:02:14 bcik volumio[20976]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 17:02:16 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 236. Aug 31 17:02:16 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:02:16 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:02:16 bcik go-librespot[21302]: go-librespot daemon starting... Aug 31 17:02:16 bcik go-librespot[21303]: time="2026-08-31T17:02:16+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 17:02:16 bcik go-librespot[21303]: time="2026-08-31T17:02:16+02:00" level=debug msg="app state loaded" Aug 31 17:02:16 bcik go-librespot[21303]: time="2026-08-31T17:02:16+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 17:02:16 bcik go-librespot[21303]: time="2026-08-31T17:02:16+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 17:02:16 bcik go-librespot[21303]: time="2026-08-31T17:02:16+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 17:02:16 bcik go-librespot[21303]: time="2026-08-31T17:02:16+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 17:02:16 bcik go-librespot[21303]: time="2026-08-31T17:02:16+02:00" level=info msg="zeroconf server listening on port 35909" Aug 31 17:02:17 bcik go-librespot[21303]: time="2026-08-31T17:02:17+02:00" level=debug msg="obtained new client token: AAEM7ZcKP+bvqJFcr1e8A59N6SER/GfK2hR+bvdhgkftLxkjWwOUN+UVeqk7V+PxYFMBA+aUOt5pUr1eDRqVejb9Qmr5/hlfGGiSbhBJG7H97kslaeEEbZrNv/XqW0A7P5lELUH87cEaJHyQYLf18fKPeDXlfwmGSy0m53ABZmRJHsU0fPppk0f6KGUireIo+rJ4/+hhAUnBJEQ4AXh/bDJrqI/PWcfYivj1o6PLmTIXFTWViqd1" Aug 31 17:02:17 bcik go-librespot[21303]: time="2026-08-31T17:02:17+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Aug 31 17:02:17 bcik go-librespot[21303]: time="2026-08-31T17:02:17+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Aug 31 17:02:17 bcik go-librespot[21303]: time="2026-08-31T17:02:17+02:00" level=debug msg="completed keyexchange" Aug 31 17:02:17 bcik go-librespot[21303]: time="2026-08-31T17:02:17+02:00" level=debug msg="completed challenge" Aug 31 17:02:17 bcik go-librespot[21303]: time="2026-08-31T17:02:17+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 17:02:17 bcik go-librespot[21303]: time="2026-08-31T17:02:17+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 17:02:17 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 17:02:17 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 17:02:17 bcik volumio[20976]: info: Initializing connection to go-librespot Websocket Aug 31 17:02:17 bcik volumio[20976]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 17:02:17 bcik volumio[20976]: info: MYVOLUMIO: Adding device Aug 31 17:02:17 bcik volumio[20976]: info: MYVOLUMIO: Evaluating Server Aug 31 17:02:18 bcik volumio[20976]: info: Setting Geolocation for MyVolumio to eu6 Aug 31 17:02:18 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 17:02:18 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 17:02:18 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 17:02:18 bcik volumio[20976]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Aug 31 17:02:19 bcik volumio[20976]: info: Updating MyVolumio device info Aug 31 17:02:19 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 17:02:19 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 17:02:19 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 17:02:20 bcik volumio[20976]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Aug 31 17:02:20 bcik volumio[20976]: info: Initializing connection to go-librespot Websocket Aug 31 17:02:20 bcik volumio[20976]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 17:02:20 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 237. Aug 31 17:02:20 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:02:20 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:02:20 bcik go-librespot[21330]: go-librespot daemon starting... Aug 31 17:02:20 bcik go-librespot[21331]: time="2026-08-31T17:02:20+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 17:02:20 bcik go-librespot[21331]: time="2026-08-31T17:02:20+02:00" level=debug msg="app state loaded" Aug 31 17:02:20 bcik go-librespot[21331]: time="2026-08-31T17:02:20+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 17:02:20 bcik go-librespot[21331]: time="2026-08-31T17:02: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]" Aug 31 17:02:20 bcik go-librespot[21331]: time="2026-08-31T17:02: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]" Aug 31 17:02:20 bcik go-librespot[21331]: time="2026-08-31T17:02: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]" Aug 31 17:02:20 bcik go-librespot[21331]: time="2026-08-31T17:02:20+02:00" level=info msg="zeroconf server listening on port 39673" Aug 31 17:02:20 bcik go-librespot[21331]: time="2026-08-31T17:02:20+02:00" level=debug msg="obtained new client token: AAF3cR3Qo1GSI2a0XQlFYKq5ssv7lpsPlL5xfHz9hlp6A/jGQrXXzB12VEH7dm6Fxdbpc4LOrZ7IiBThQF1b1STx/U37JtGS1UpYwXsnWl28X5RRo4L3zK6ge+VV+HZ/85qARXy4r/sh5PYmDB3CwcK3U9SU13PQvkQ0e+6mpaqWFjU3scM6//RoFCeYFG18u0JgnLrRzjgMxMRpBVD9CcS1jL8ZPnEkidfnhYN2swPoW9Nl8dq/e6w=" Aug 31 17:02:20 bcik go-librespot[21331]: time="2026-08-31T17:02:20+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 17:02:20 bcik go-librespot[21331]: time="2026-08-31T17:02:20+02:00" level=debug msg="completed keyexchange" Aug 31 17:02:20 bcik go-librespot[21331]: time="2026-08-31T17:02:20+02:00" level=debug msg="completed challenge" Aug 31 17:02:20 bcik go-librespot[21331]: time="2026-08-31T17:02:20+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 17:02:21 bcik go-librespot[21331]: time="2026-08-31T17:02:21+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 17:02:21 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 17:02:21 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 17:02:23 bcik volumio[20976]: info: Initializing connection to go-librespot Websocket Aug 31 17:02:23 bcik volumio[20976]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 17:02:24 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 238. Aug 31 17:02:24 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:02:24 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:02:24 bcik go-librespot[21356]: go-librespot daemon starting... Aug 31 17:02:24 bcik go-librespot[21357]: time="2026-08-31T17:02:24+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 17:02:24 bcik go-librespot[21357]: time="2026-08-31T17:02:24+02:00" level=debug msg="app state loaded" Aug 31 17:02:24 bcik go-librespot[21357]: time="2026-08-31T17:02:24+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 17:02:24 bcik go-librespot[21357]: time="2026-08-31T17:02: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-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 17:02:24 bcik go-librespot[21357]: time="2026-08-31T17:02:24+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 17:02:24 bcik go-librespot[21357]: time="2026-08-31T17:02:24+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 17:02:24 bcik go-librespot[21357]: time="2026-08-31T17:02:24+02:00" level=info msg="zeroconf server listening on port 36807" Aug 31 17:02:24 bcik go-librespot[21357]: time="2026-08-31T17:02:24+02:00" level=debug msg="obtained new client token: AAFItDuLpl+zkHCdguUDXoYwnTjjG5KQPEQLRXwVhKInEGEOYHjvs2xcJXLJbXS1TPOW+u58EEFLQSEyiKzedXQkLPS1uTDALujU5Ayo0zMViYqiyyMHc1LD/dxQVxH32Cf7z8BxdVytSvuR2b+IKKDrHQPSgC0LARS1q1uEsBqHcQwilV95h+It0Yb9uVy6ljcuUqDjfip+nF8HQBdl0bB/gyhy/uwFMX8bL6R3utgWTvdw5QTqrxU=" Aug 31 17:02:24 bcik go-librespot[21357]: time="2026-08-31T17:02:24+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 17:02:24 bcik go-librespot[21357]: time="2026-08-31T17:02:24+02:00" level=debug msg="completed keyexchange" Aug 31 17:02:24 bcik go-librespot[21357]: time="2026-08-31T17:02:24+02:00" level=debug msg="completed challenge" Aug 31 17:02:24 bcik go-librespot[21357]: time="2026-08-31T17:02:24+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 17:02:24 bcik go-librespot[21357]: time="2026-08-31T17:02:24+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 17:02:24 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 17:02:24 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 17:02:26 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 31 17:02:26 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Aug 31 17:02:26 bcik volumio[20976]: info: CoreCommandRouter::volumioGetState Aug 31 17:02:26 bcik volumio[20976]: info: CorePlayQueue::getTrack 0 Aug 31 17:02:26 bcik volumio[20976]: info: Initializing connection to go-librespot Websocket Aug 31 17:02:26 bcik volumio[20976]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 17:02:27 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 239. Aug 31 17:02:27 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:02:27 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:02:27 bcik go-librespot[21367]: go-librespot daemon starting... Aug 31 17:02:27 bcik go-librespot[21368]: time="2026-08-31T17:02:27+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 17:02:27 bcik go-librespot[21368]: time="2026-08-31T17:02:27+02:00" level=debug msg="app state loaded" Aug 31 17:02:27 bcik go-librespot[21368]: time="2026-08-31T17:02:27+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 17:02:27 bcik go-librespot[21368]: time="2026-08-31T17:02:27+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 17:02:27 bcik go-librespot[21368]: time="2026-08-31T17:02:27+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 17:02:27 bcik go-librespot[21368]: time="2026-08-31T17:02:27+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 17:02:27 bcik go-librespot[21368]: time="2026-08-31T17:02:27+02:00" level=info msg="zeroconf server listening on port 39655" Aug 31 17:02:27 bcik go-librespot[21368]: time="2026-08-31T17:02:27+02:00" level=debug msg="obtained new client token: AAFLnR2TYuyAsTEZpkrUnGrvBu475as8YUJDEmaJJi3KlodHuHy4YJECZdWup0lffpGRVpAjJnIBYA09JLgd3JTMnCNc22UpEwTJxU5kahTBpburJ5E1MMrWPN4CYdqmuMmDGcyVEm5AKrc2+CsNuhDw2JGqZRyKWeuGqYE88L1UdNBnbBDtT5B2VM11AsA7rv9oLDFAbOy+yUpbv97PnVbUu4mo64kACx9fIA77SsBDh2uIjSe/Xsc=" Aug 31 17:02:27 bcik go-librespot[21368]: time="2026-08-31T17:02:27+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Aug 31 17:02:28 bcik go-librespot[21368]: time="2026-08-31T17:02:28+02:00" level=debug msg="completed keyexchange" Aug 31 17:02:28 bcik go-librespot[21368]: time="2026-08-31T17:02:28+02:00" level=debug msg="completed challenge" Aug 31 17:02:28 bcik go-librespot[21368]: time="2026-08-31T17:02:28+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 17:02:28 bcik go-librespot[21368]: time="2026-08-31T17:02:28+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 17:02:28 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 17:02:28 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 17:02:29 bcik volumio[20976]: info: Initializing connection to go-librespot Websocket Aug 31 17:02:29 bcik volumio[20976]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 17:02:31 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:02:31 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:02:31 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Aug 31 17:02:31 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Aug 31 17:02:31 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Aug 31 17:02:31 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Aug 31 17:02:31 bcik volumio[20976]: info: CoreCommandRouter::volumioGetBrowseSources Aug 31 17:02:31 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 17:02:31 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 240. Aug 31 17:02:31 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:02:31 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 17:02:31 bcik go-librespot[21391]: go-librespot daemon starting... Aug 31 17:02:31 bcik go-librespot[21392]: time="2026-08-31T17:02:31+02:00" level=info msg="running go-librespot 0.6.2" Aug 31 17:02:31 bcik go-librespot[21392]: time="2026-08-31T17:02:31+02:00" level=debug msg="app state loaded" Aug 31 17:02:31 bcik go-librespot[21392]: time="2026-08-31T17:02:31+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 17:02:31 bcik volumio[20976]: error: MyVolumio Plugin failed to authenticate in a timely fashion Aug 31 17:02:31 bcik volumio[20976]: info: Completed starting MyVolumio Plugin Aug 31 17:02:31 bcik volumio[20976]: [Metrics] CommandRouter: 30s 668.01ms Aug 31 17:02:31 bcik volumio[20976]: info: CoreCommandRouter::volumiosetStartupVolume Aug 31 17:02:31 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 17:02:31 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 17:02:31 bcik volumio[20976]: info: CoreCommandRouter::Close All Modals sent Aug 31 17:02:31 bcik volumio[20976]: info: CoreCommandRouter::Close All Modals sent Aug 31 17:02:31 bcik go-librespot[21392]: time="2026-08-31T17:02:31+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 17:02:31 bcik go-librespot[21392]: time="2026-08-31T17:02:31+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 17:02:31 bcik go-librespot[21392]: time="2026-08-31T17:02:31+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 17:02:31 bcik go-librespot[21392]: time="2026-08-31T17:02:31+02:00" level=info msg="zeroconf server listening on port 41955" Aug 31 17:02:31 bcik go-librespot[21392]: time="2026-08-31T17:02:31+02:00" level=debug msg="obtained new client token: AAHOS5zYg9dDpgWCpsID8COo+FaoMAYXlOMW942VG9Z9Al/6pjCRvmRFRxGrWGTfGpzpgh0tK85XX1XQ+AfmYqZfdn8mFHUerxzqyVWpJqiWprkRNcJ2uZ+Sk39Iq0w17ZkUhZHbypuwpWyP+fNi+DkbynXqn5fnGDJ0TDW8q7X/WCuFBqeOG+LxSV/+FU+INoO/8lIa1JhszqpllW7atCQG951BIdvfsenG+wrfHBb1BVjhHQDNiiE=" Aug 31 17:02:31 bcik go-librespot[21392]: time="2026-08-31T17:02:31+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Aug 31 17:02:31 bcik go-librespot[21392]: time="2026-08-31T17:02:31+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Aug 31 17:02:32 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 17:02:32 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 17:02:32 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 31 17:02:32 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Aug 31 17:02:32 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 31 17:02:32 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Aug 31 17:02:32 bcik volumio-remote-updater[962]: Test mode disabled Aug 31 17:02:32 bcik volumio-remote-updater[962]: Alpha mode disabled Aug 31 17:02:32 bcik volumio-remote-updater[962]: Alpha legacy test mode disabled Aug 31 17:02:32 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Aug 31 17:02:32 bcik volumio[20976]: info: Initializing connection to go-librespot Websocket Aug 31 17:02:32 bcik go-librespot[21392]: time="2026-08-31T17:02:32+02:00" level=debug msg="new websocket client" Aug 31 17:02:32 bcik volumio[20976]: info: Connection to go-librespot Websocket established Aug 31 17:02:32 bcik volumio[20976]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Aug 31 17:02:32 bcik volumio[20976]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Aug 31 17:02:35 bcik volumio[20976]: info: Getting Spotify volume Aug 31 17:02:35 bcik volumio[20976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Aug 31 17:02:35 bcik volumio[20976]: info: CoreCommandRouter::volumioGetState Aug 31 17:02:35 bcik volumio[20976]: info: CorePlayQueue::getTrack 0 Aug 31 17:02:35 bcik volumio[20976]: SPOTIFY: RECEIVED VOLUMIO VOLUME 53 Aug 31 17:02:35 bcik volumio[20976]: SPOTIFY: SPOTIFY VOLUME undefined Aug 31 17:02:35 bcik volumio[20976]: SPOTIFY: VOLUMIO VOLUME 53 Aug 31 17:02:35 bcik volumio[20976]: info: Aligning Spotify Volume to Volumio Volume Aug 31 17:02:35 bcik volumio[20976]: info: CoreCommandRouter::volumioGetState Aug 31 17:02:35 bcik volumio[20976]: info: CorePlayQueue::getTrack 0 Aug 31 17:02:35 bcik volumio[20976]: info: Setting Spotify Volume from Volumio: 53 Aug 31 17:02:35 bcik go-librespot[21392]: time="2026-08-31T17:02:35+02:00" level=debug msg="completed keyexchange" Aug 31 17:02:35 bcik go-librespot[21392]: time="2026-08-31T17:02:35+02:00" level=debug msg="completed challenge" Aug 31 17:02:35 bcik go-librespot[21392]: time="2026-08-31T17:02:35+02:00" level=info msg="authenticated AP" username="la***pl" Aug 31 17:02:35 bcik go-librespot[21392]: time="2026-08-31T17:02:35+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 17:02:35 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 17:02:35 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 17:02:35 bcik volumio[20976]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 17:02:35 bcik volumio[20976]: Error: socket hang up Aug 31 17:02:35 bcik volumio[20976]: at connResetException (node:internal/errors:720:14) Aug 31 17:02:35 bcik volumio[20976]: at Socket.socketOnEnd (node:_http_client:519:23) Aug 31 17:02:35 bcik volumio[20976]: at Socket.emit (node:events:526:35) Aug 31 17:02:35 bcik volumio[20976]: at endReadableNT (node:internal/streams/readable:1376:12) Aug 31 17:02:35 bcik volumio[20976]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Aug 31 17:02:35 bcik volumio[20976]: code: 'ECONNRESET', Aug 31 17:02:35 bcik volumio[20976]: response: undefined Aug 31 17:02:35 bcik volumio[20976]: } Aug 31 17:02:35 bcik volumio[20976]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 17:02:35 bcik sudo[21422]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-31 17:01' Aug 31 17:02:35 bcik sudo[21422]: 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"