Aug 29 14:01:00 keylimepi volumio[2060]: info: Applying required configuration parameters for plugin fusiondsp Aug 29 14:01:00 keylimepi volumio[2224]: Forking 3 albumart workers Aug 29 14:01:01 keylimepi volumio[2060]: info: Loading plugin "pandora"... Aug 29 14:01:01 keylimepi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Aug 29 14:01:01 keylimepi systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:01:01 keylimepi systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:01:01 keylimepi go-librespot[2272]: go-librespot daemon starting... Aug 29 14:01:02 keylimepi go-librespot[2274]: time="2026-08-29T14:01:02-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 14:01:02 keylimepi go-librespot[2274]: time="2026-08-29T14:01:02-04:00" level=debug msg="app state loaded" Aug 29 14:01:02 keylimepi go-librespot[2274]: time="2026-08-29T14:01:02-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 14:01:02 keylimepi go-librespot[2274]: time="2026-08-29T14:01:02-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 14:01:02 keylimepi go-librespot[2274]: time="2026-08-29T14:01:02-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 14:01:02 keylimepi go-librespot[2274]: time="2026-08-29T14:01:02-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 14:01:02 keylimepi go-librespot[2274]: time="2026-08-29T14:01:02-04:00" level=info msg="zeroconf server listening on port 34541" Aug 29 14:01:02 keylimepi go-librespot[2274]: time="2026-08-29T14:01:02-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 14:01:02 keylimepi go-librespot[2274]: time="2026-08-29T14:01:02-04:00" level=debug msg="obtained new client token: AAFVMniYkJnmoLhHR9QvLve83oneUlHS9hx9DoiyTUQbZApNzCDcPKxCZbhT3OQHxfZZN2figrDXBxJr/43zgEhNyAKUAB41yN6MnO+/ouFi9/ctf3MaSEvosAelhCehUEVfjxri1Z6fksBJv3aD4TVyB8yh9fjZgUOR1X6ypEYB9AuTmWi3Az+u14AWPeEJ1B0tARn8WwGHxdeaTUFSGUYS3SkoLMyQTRJqa8ASi1fNG8uk4UVvOLrs" Aug 29 14:01:02 keylimepi go-librespot[2274]: time="2026-08-29T14:01:02-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 29 14:01:03 keylimepi go-librespot[2274]: time="2026-08-29T14:01:03-04:00" level=debug msg="completed keyexchange" Aug 29 14:01:03 keylimepi go-librespot[2274]: time="2026-08-29T14:01:03-04:00" level=debug msg="completed challenge" Aug 29 14:01:03 keylimepi go-librespot[2274]: time="2026-08-29T14:01:03-04:00" level=info msg="authenticated AP" username="dr*****4c" Aug 29 14:01:03 keylimepi go-librespot[2274]: time="2026-08-29T14:01:03-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 14:01:03 keylimepi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 14:01:03 keylimepi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 14:01:06 keylimepi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Aug 29 14:01:06 keylimepi systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:01:06 keylimepi systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:01:06 keylimepi go-librespot[2299]: go-librespot daemon starting... Aug 29 14:01:06 keylimepi go-librespot[2300]: time="2026-08-29T14:01:06-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 14:01:06 keylimepi go-librespot[2300]: time="2026-08-29T14:01:06-04:00" level=debug msg="app state loaded" Aug 29 14:01:06 keylimepi go-librespot[2300]: time="2026-08-29T14:01:06-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 14:01:07 keylimepi go-librespot[2300]: time="2026-08-29T14:01:07-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 14:01:07 keylimepi go-librespot[2300]: time="2026-08-29T14:01:07-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 14:01:07 keylimepi go-librespot[2300]: time="2026-08-29T14:01:07-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 14:01:07 keylimepi go-librespot[2300]: time="2026-08-29T14:01:07-04:00" level=info msg="zeroconf server listening on port 39661" Aug 29 14:01:07 keylimepi go-librespot[2300]: time="2026-08-29T14:01:07-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 14:01:07 keylimepi go-librespot[2300]: time="2026-08-29T14:01:07-04:00" level=debug msg="obtained new client token: AAH7+MOsH1lCZT9qAt1+iol/s7yQfnTtMfOkuVvjuLak3afqHhr7+gI/bzFiUykuakfes6txYbIgDwwrJtbWl8CVh7QPaC2EdyUnb1f+zm8SlsU40AzV0F0xKMudw8YvFZZg0Qb63u1ndzkn+EyL1U+7L+kBrLF4x5yDpOyXzocJl8SgnYNG+Gcz5Fh7ZW+GS4zADbDudExf7WSDyuGvDpyBQsSXeiMxcJwW7oocsA/RYI9HrAuMPao6" Aug 29 14:01:07 keylimepi go-librespot[2300]: time="2026-08-29T14:01:07-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 29 14:01:07 keylimepi go-librespot[2300]: time="2026-08-29T14:01:07-04:00" level=debug msg="completed keyexchange" Aug 29 14:01:07 keylimepi go-librespot[2300]: time="2026-08-29T14:01:07-04:00" level=debug msg="completed challenge" Aug 29 14:01:07 keylimepi go-librespot[2300]: time="2026-08-29T14:01:07-04:00" level=info msg="authenticated AP" username="dr*****4c" Aug 29 14:01:08 keylimepi go-librespot[2300]: time="2026-08-29T14:01:08-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 14:01:08 keylimepi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 14:01:08 keylimepi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 14:01:11 keylimepi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Aug 29 14:01:11 keylimepi systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:01:11 keylimepi systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:01:11 keylimepi go-librespot[2309]: go-librespot daemon starting... Aug 29 14:01:11 keylimepi go-librespot[2310]: time="2026-08-29T14:01:11-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 14:01:11 keylimepi go-librespot[2310]: time="2026-08-29T14:01:11-04:00" level=debug msg="app state loaded" Aug 29 14:01:11 keylimepi go-librespot[2310]: time="2026-08-29T14:01:11-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 14:01:12 keylimepi go-librespot[2310]: time="2026-08-29T14:01:12-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 14:01:12 keylimepi go-librespot[2310]: time="2026-08-29T14:01:12-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 14:01:12 keylimepi go-librespot[2310]: time="2026-08-29T14:01:12-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 14:01:12 keylimepi go-librespot[2310]: time="2026-08-29T14:01:12-04:00" level=info msg="zeroconf server listening on port 35745" Aug 29 14:01:12 keylimepi go-librespot[2310]: time="2026-08-29T14:01:12-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 14:01:12 keylimepi go-librespot[2310]: time="2026-08-29T14:01:12-04:00" level=debug msg="obtained new client token: AAGrYboyV5dE+0of/AW2gO+6vNqKid09CV9kbeKunZZ8jTNBDo2E9yFPOVrf9tLUkCZaFlDKbZZf58F9M7Rx3/yt7IozjqiyLmnsV4SvvAOQ6M2UfDmHKn+pXL31xLHp65JGE/bL+Ee/m8ORlwXZa+C4/FDu3B0LkEYKDrBqIo/tXHUsXQlXutIvHPTpAUlljuNfOb94WCeWWNY+GftsArK2SQDXDeG0t8Vi/dGUCybrqfnyeW51Bg==" Aug 29 14:01:12 keylimepi go-librespot[2310]: time="2026-08-29T14:01:12-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 29 14:01:12 keylimepi go-librespot[2310]: time="2026-08-29T14:01:12-04:00" level=debug msg="completed keyexchange" Aug 29 14:01:12 keylimepi go-librespot[2310]: time="2026-08-29T14:01:12-04:00" level=debug msg="completed challenge" Aug 29 14:01:12 keylimepi go-librespot[2310]: time="2026-08-29T14:01:12-04:00" level=info msg="authenticated AP" username="dr*****4c" Aug 29 14:01:12 keylimepi go-librespot[2310]: time="2026-08-29T14:01:12-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 14:01:12 keylimepi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 14:01:12 keylimepi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 14:01:13 keylimepi volumio-remote-updater[703]: [2026-08-29 14:01:13] [connect] Successful connection Aug 29 14:01:15 keylimepi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Aug 29 14:01:15 keylimepi systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:01:15 keylimepi systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:01:15 keylimepi go-librespot[2334]: go-librespot daemon starting... Aug 29 14:01:16 keylimepi go-librespot[2335]: time="2026-08-29T14:01:16-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 14:01:16 keylimepi go-librespot[2335]: time="2026-08-29T14:01:16-04:00" level=debug msg="app state loaded" Aug 29 14:01:16 keylimepi go-librespot[2335]: time="2026-08-29T14:01:16-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 14:01:16 keylimepi go-librespot[2335]: time="2026-08-29T14:01:16-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Aug 29 14:01:16 keylimepi go-librespot[2335]: time="2026-08-29T14:01:16-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 29 14:01:16 keylimepi go-librespot[2335]: time="2026-08-29T14:01:16-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 29 14:01:16 keylimepi go-librespot[2335]: time="2026-08-29T14:01:16-04:00" level=info msg="zeroconf server listening on port 37793" Aug 29 14:01:16 keylimepi go-librespot[2335]: time="2026-08-29T14:01:16-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 14:01:17 keylimepi go-librespot[2335]: time="2026-08-29T14:01:17-04:00" level=debug msg="obtained new client token: AAHl2IwBHJiQMArcZWmmg1AxeX0tox3dVcmkEeh41dcDKBHfZpSSvYFtKVBT/4vGQScX3/jPrQeuyZS6HkYqh7XHCBR0m5SlkTFRe0hOgkQMQieNv9ZanSORINNWi2CBhg11TGdFfue9OL5/aSdE0MnfKVW1qxFmt1AvbIiy5sYUgryo2rbnBaxn2wLwonZNkCpyNFmNdoSdd6IK5ZNT3yqIE421LzrL7wVhrjRE59UR8cC3qutDmyyz" Aug 29 14:01:17 keylimepi go-librespot[2335]: time="2026-08-29T14:01:17-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 29 14:01:17 keylimepi go-librespot[2335]: time="2026-08-29T14:01:17-04:00" level=debug msg="completed keyexchange" Aug 29 14:01:17 keylimepi go-librespot[2335]: time="2026-08-29T14:01:17-04:00" level=debug msg="completed challenge" Aug 29 14:01:17 keylimepi go-librespot[2335]: time="2026-08-29T14:01:17-04:00" level=info msg="authenticated AP" username="dr*****4c" Aug 29 14:01:17 keylimepi go-librespot[2335]: time="2026-08-29T14:01:17-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 14:01:17 keylimepi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 14:01:17 keylimepi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 14:01:17 keylimepi volumio[2244]: Starting albumart workers Aug 29 14:01:17 keylimepi volumio[2245]: Starting albumart workers Aug 29 14:01:19 keylimepi volumio[2246]: Starting albumart workers Aug 29 14:01:20 keylimepi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Aug 29 14:01:20 keylimepi systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:01:20 keylimepi systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:01:20 keylimepi go-librespot[2344]: go-librespot daemon starting... Aug 29 14:01:20 keylimepi go-librespot[2345]: time="2026-08-29T14:01:20-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 14:01:20 keylimepi go-librespot[2345]: time="2026-08-29T14:01:20-04:00" level=debug msg="app state loaded" Aug 29 14:01:20 keylimepi go-librespot[2345]: time="2026-08-29T14:01:20-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 14:01:21 keylimepi go-librespot[2345]: time="2026-08-29T14:01:21-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 14:01:21 keylimepi go-librespot[2345]: time="2026-08-29T14:01:21-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 14:01:21 keylimepi go-librespot[2345]: time="2026-08-29T14:01:21-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 14:01:21 keylimepi go-librespot[2345]: time="2026-08-29T14:01:21-04:00" level=info msg="zeroconf server listening on port 43361" Aug 29 14:01:21 keylimepi go-librespot[2345]: time="2026-08-29T14:01:21-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 14:01:21 keylimepi go-librespot[2345]: time="2026-08-29T14:01:21-04:00" level=debug msg="obtained new client token: AAHs1vQtDkDbsskTy3/pNTBRY8XNO2UeDtrzfJckAsb3c51HCUxyFt96AxZzB/lY5HKZwmRlYGdwt/ANT4DR0ZgXZjN0WNmaqS2RtIi4Z1771l8yb8rE3ZUWjNiplE3LpOCoqBPzGlz+A1+wC2536ah6ioNpaqleT7IoeY3kP+1BvCx5Bt9pW5rtHBUCzBVGMCLmJm6j5rJO3quXmngm8rZt2c15liroMUL8XfJWyJQkpvmXfAqJGsxR" Aug 29 14:01:21 keylimepi go-librespot[2345]: time="2026-08-29T14:01:21-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 29 14:01:21 keylimepi go-librespot[2345]: time="2026-08-29T14:01:21-04:00" level=debug msg="completed keyexchange" Aug 29 14:01:21 keylimepi go-librespot[2345]: time="2026-08-29T14:01:21-04:00" level=debug msg="completed challenge" Aug 29 14:01:21 keylimepi go-librespot[2345]: time="2026-08-29T14:01:21-04:00" level=info msg="authenticated AP" username="dr*****4c" Aug 29 14:01:22 keylimepi go-librespot[2345]: time="2026-08-29T14:01:22-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 14:01:22 keylimepi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 14:01:22 keylimepi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 14:01:22 keylimepi volumio[2060]: info: Applying required configuration parameters for plugin pandora Aug 29 14:01:24 keylimepi volumio[2060]: info: Loading i18n strings for locale en Aug 29 14:01:24 keylimepi volumio[2060]: Updating browse sources language Aug 29 14:01:24 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 14:01:25 keylimepi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Aug 29 14:01:25 keylimepi systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:01:25 keylimepi systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:01:25 keylimepi go-librespot[2369]: go-librespot daemon starting... Aug 29 14:01:25 keylimepi go-librespot[2370]: time="2026-08-29T14:01:25-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 14:01:25 keylimepi go-librespot[2370]: time="2026-08-29T14:01:25-04:00" level=debug msg="app state loaded" Aug 29 14:01:25 keylimepi go-librespot[2370]: time="2026-08-29T14:01:25-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 14:01:26 keylimepi go-librespot[2370]: time="2026-08-29T14:01:26-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 14:01:26 keylimepi go-librespot[2370]: time="2026-08-29T14:01:26-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 14:01:26 keylimepi go-librespot[2370]: time="2026-08-29T14:01:26-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 14:01:26 keylimepi go-librespot[2370]: time="2026-08-29T14:01:26-04:00" level=info msg="zeroconf server listening on port 46689" Aug 29 14:01:26 keylimepi go-librespot[2370]: time="2026-08-29T14:01:26-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 14:01:26 keylimepi go-librespot[2370]: time="2026-08-29T14:01:26-04:00" level=debug msg="obtained new client token: AAH9ishIzVXEHa9G0hnOJaBETN3gsgUwrj3vFN9famUiwWs423KJTV/i4SCDLmgiHtqzmqXAvC2G5adYXQlZey7UP7RvXB3Ts5329TzxpT9JepZPJ5GPz3Vmj3MYfJSIiksz+csJWO+T1gUyeyKZ8acEBwVO+g/RmleJggKCCndbjyTfIYgEbJDSXXNPbNqTpXlqK3KYxHuVWncfDMR7kB+68UOb21QwTDR+roLtAU6pWO32Gzo+/hvg" Aug 29 14:01:26 keylimepi go-librespot[2370]: time="2026-08-29T14:01:26-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 29 14:01:26 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 29 14:01:26 keylimepi volumio[2060]: info: CoreCommandRouter::initPlayerControls Aug 29 14:01:26 keylimepi go-librespot[2370]: time="2026-08-29T14:01:26-04:00" level=debug msg="completed keyexchange" Aug 29 14:01:26 keylimepi go-librespot[2370]: time="2026-08-29T14:01:26-04:00" level=debug msg="completed challenge" Aug 29 14:01:26 keylimepi go-librespot[2370]: time="2026-08-29T14:01:26-04:00" level=info msg="authenticated AP" username="dr*****4c" Aug 29 14:01:26 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:01:26 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:01:26 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:01:26 keylimepi go-librespot[2370]: time="2026-08-29T14:01:26-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 14:01:26 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:01:26 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:01:26 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:01:26 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:01:26 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:01:26 keylimepi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 14:01:26 keylimepi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 14:01:27 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 29 14:01:27 keylimepi volumio[2060]: Express server listening on port 3000 Aug 29 14:01:27 keylimepi volumio[2060]: [Metrics] WebUI: 51s 229.51ms Aug 29 14:01:27 keylimepi volumio[2060]: info: CoreStateMachine::resetVolumioState Aug 29 14:01:27 keylimepi volumio[2060]: info: CoreStateMachine::getcurrentVolume Aug 29 14:01:27 keylimepi volumio[2060]: info: CoreCommandRouter::volumioRetrievevolume Aug 29 14:01:27 keylimepi volumio[2060]: info: CoreStateMachine::pushState Aug 29 14:01:27 keylimepi volumio[2060]: info: CorePlayQueue::getTrack 0 Aug 29 14:01:27 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 14:01:27 keylimepi volumio[2060]: info: CoreCommandRouter::volumioPushState Aug 29 14:01:27 keylimepi sudo[2403]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 29 14:01:27 keylimepi sudo[2403]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 14:01:28 keylimepi sudo[2403]: pam_unix(sudo:session): session closed for user root Aug 29 14:01:28 keylimepi sudo[2405]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 29 14:01:28 keylimepi sudo[2405]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 14:01:28 keylimepi volumio-remote-updater[703]: [2026-08-29 14:01:28] [connect] Successful connection Aug 29 14:01:28 keylimepi sudo[2405]: pam_unix(sudo:session): session closed for user root Aug 29 14:01:28 keylimepi volumio[2060]: info: Volumio Network Manager: Network status updated: 2 Aug 29 14:01:29 keylimepi volumio[2060]: verbose: New Socket.io Connection to 192.168.2.110:3000 from 192.168.2.201 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Aug 29 14:01:30 keylimepi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Aug 29 14:01:30 keylimepi systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:01:30 keylimepi systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:01:30 keylimepi go-librespot[2409]: go-librespot daemon starting... Aug 29 14:01:30 keylimepi go-librespot[2410]: time="2026-08-29T14:01:30-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 14:01:30 keylimepi go-librespot[2410]: time="2026-08-29T14:01:30-04:00" level=debug msg="app state loaded" Aug 29 14:01:30 keylimepi go-librespot[2410]: time="2026-08-29T14:01:30-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 14:01:30 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 14:01:30 keylimepi go-librespot[2410]: time="2026-08-29T14:01:30-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 14:01:30 keylimepi go-librespot[2410]: time="2026-08-29T14:01:30-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 14:01:30 keylimepi go-librespot[2410]: time="2026-08-29T14:01:30-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 14:01:30 keylimepi go-librespot[2410]: time="2026-08-29T14:01:30-04:00" level=info msg="zeroconf server listening on port 41497" Aug 29 14:01:30 keylimepi volumio[2060]: verbose: New Socket.io Connection to 192.168.2.110:3000 from 192.168.2.201 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Aug 29 14:01:30 keylimepi go-librespot[2410]: time="2026-08-29T14:01:30-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 14:01:30 keylimepi volumio[2060]: info: CoreStateMachine::setRepeat null single undefined Aug 29 14:01:30 keylimepi volumio[2060]: info: CoreStateMachine::pushState Aug 29 14:01:30 keylimepi volumio[2060]: info: CorePlayQueue::getTrack 0 Aug 29 14:01:30 keylimepi volumio[2060]: info: CoreCommandRouter::volumioPushState Aug 29 14:01:30 keylimepi volumio[2060]: info: CoreStateMachine::setRandom true Aug 29 14:01:30 keylimepi volumio[2060]: info: CoreStateMachine::pushState Aug 29 14:01:30 keylimepi volumio[2060]: info: CorePlayQueue::getTrack 0 Aug 29 14:01:30 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 14:01:30 keylimepi volumio[2060]: info: CoreCommandRouter::volumioPushState Aug 29 14:01:31 keylimepi volumio[2060]: info: Setting Device type: Raspberry PI Aug 29 14:01:31 keylimepi go-librespot[2410]: time="2026-08-29T14:01:31-04:00" level=debug msg="obtained new client token: AAEAoeUfo91OLcyn55rDeF0TTdkNCe0UA3eK0Qb/O1fGO4X5VqtBcRp48lwzq3zXtpBDTZRKRZKh3njXBGYwAc8OBjsi44GWNBBHiOFGIaIrV+MVingUPQ8Dd+2up6onYvwovwDJmesiEXedM4lxSfweaaMeiSWlsp9arcK0ZXvfvJiZEgwdMVtas6cdXGnGhrTDwbUGIV/Ls4D3lo8B/l+9pCAGbAu6f7qmzuCg/AHJR61odgnDDA==" Aug 29 14:01:31 keylimepi volumio[2060]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Aug 29 14:01:31 keylimepi volumio[2060]: info: USB Boot Capable - System SBC Revision found in cpuinfo: a22082 Aug 29 14:01:31 keylimepi volumio[2060]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Aug 29 14:01:31 keylimepi go-librespot[2410]: time="2026-08-29T14:01:31-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 29 14:01:31 keylimepi go-librespot[2410]: time="2026-08-29T14:01:31-04:00" level=debug msg="completed keyexchange" Aug 29 14:01:31 keylimepi go-librespot[2410]: time="2026-08-29T14:01:31-04:00" level=debug msg="completed challenge" Aug 29 14:01:31 keylimepi go-librespot[2410]: time="2026-08-29T14:01:31-04:00" level=info msg="authenticated AP" username="dr*****4c" Aug 29 14:01:31 keylimepi volumio[2060]: verbose: New Socket.io Connection to 192.168.2.110:3000 from 192.168.2.201 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Aug 29 14:01:31 keylimepi go-librespot[2410]: time="2026-08-29T14:01:31-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 14:01:31 keylimepi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 14:01:31 keylimepi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 14:01:31 keylimepi volumio[2060]: info: Completed loading Core Plugins Aug 29 14:01:31 keylimepi volumio[2060]: info: Preparing to generate the ALSA configuration file Aug 29 14:01:31 keylimepi volumio[2060]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Aug 29 14:01:31 keylimepi volumio[2060]: info: Reading ALSA contributions from plugins. Aug 29 14:01:31 keylimepi volumio[2060]: verbose: New Socket.io Connection to 192.168.2.110:3000 from 192.168.2.201 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Aug 29 14:01:32 keylimepi sudo[2427]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Aug 29 14:01:32 keylimepi sudo[2427]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 14:01:32 keylimepi volumio[2060]: info: Discovery: adding 379f65fd-7a27-4dc9-824b-91bca33fdbf6 Aug 29 14:01:32 keylimepi volumio[2060]: info: Discovery: Found device HigherPi Aug 29 14:01:32 keylimepi sudo[2427]: pam_unix(sudo:session): session closed for user root Aug 29 14:01:32 keylimepi volumio[2060]: info: Discovery: Connecting to remote: 192.168.2.201 Aug 29 14:01:32 keylimepi volumio[2060]: info: Discovery: adding 586e5167-f0bd-4a5e-8634-b7cf3f2f3a31 Aug 29 14:01:32 keylimepi volumio[2060]: info: Discovery: Found device KeyLimePi Aug 29 14:01:32 keylimepi volumio[2060]: info: CoreCommandRouter::volumioGetState Aug 29 14:01:32 keylimepi volumio[2060]: info: CorePlayQueue::getTrack 0 Aug 29 14:01:33 keylimepi volumio[2060]: verbose: New Socket.io Connection to 192.168.2.110:3000 from 192.168.2.201 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Aug 29 14:01:33 keylimepi volumio[2060]: info: Discovery: this is already registered, 586e5167-f0bd-4a5e-8634-b7cf3f2f3a31 Aug 29 14:01:33 keylimepi volumio[2060]: info: Discovery: Found device KeyLimePi Aug 29 14:01:33 keylimepi volumio[2060]: info: CoreCommandRouter::volumioGetState Aug 29 14:01:33 keylimepi volumio[2060]: info: CorePlayQueue::getTrack 0 Aug 29 14:01:33 keylimepi volumio[2060]: info: Upmpdcli Daemon Started Aug 29 14:01:33 keylimepi volumio[2060]: verbose: New Socket.io Connection to 192.168.2.110:3000 from 192.168.2.201 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Aug 29 14:01:34 keylimepi volumio[2060]: verbose: New Socket.io Connection to 192.168.2.110:3000 from 192.168.2.201 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Aug 29 14:01:34 keylimepi volumio[2060]: verbose: New Socket.io Connection to 192.168.2.110:3000 from 192.168.2.201 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Aug 29 14:01:34 keylimepi volumio[2060]: info: Discovery: Connected to remote: 192.168.2.201 Aug 29 14:01:34 keylimepi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Aug 29 14:01:34 keylimepi systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:01:34 keylimepi systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:01:34 keylimepi go-librespot[2429]: go-librespot daemon starting... Aug 29 14:01:34 keylimepi volumio[2060]: info: Asound.conf file unchanged, so no further update is needed Aug 29 14:01:34 keylimepi volumio[2060]: info: Output device has changed, restarting MPD Aug 29 14:01:34 keylimepi go-librespot[2430]: time="2026-08-29T14:01:34-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 14:01:34 keylimepi go-librespot[2430]: time="2026-08-29T14:01:34-04:00" level=debug msg="app state loaded" Aug 29 14:01:34 keylimepi go-librespot[2430]: time="2026-08-29T14:01:34-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 14:01:34 keylimepi sudo[2439]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 29 14:01:34 keylimepi sudo[2439]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 14:01:34 keylimepi sudo[2439]: pam_unix(sudo:session): session closed for user root Aug 29 14:01:34 keylimepi volumio[2060]: info: Output device has changed, restarting Shairport Sync Aug 29 14:01:34 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:01:34 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 14:01:35 keylimepi sudo[2442]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 29 14:01:35 keylimepi sudo[2442]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 14:01:35 keylimepi volumio[2060]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 29 14:01:35 keylimepi volumio[2060]: info: ___________ START PLUGINS ___________ Aug 29 14:01:35 keylimepi volumio[2060]: info: ControllerMpd::onStart: Initializing MPD Aug 29 14:01:35 keylimepi volumio[2060]: info: Creating MPD Configuration file Aug 29 14:01:35 keylimepi systemd[1]: Stopping mpd.service - Music Player Daemon... Aug 29 14:01:35 keylimepi go-librespot[2430]: time="2026-08-29T14:01:35-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 14:01:35 keylimepi go-librespot[2430]: time="2026-08-29T14:01:35-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 14:01:35 keylimepi go-librespot[2430]: time="2026-08-29T14:01:35-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 14:01:35 keylimepi go-librespot[2430]: time="2026-08-29T14:01:35-04:00" level=info msg="zeroconf server listening on port 38961" Aug 29 14:01:35 keylimepi go-librespot[2430]: time="2026-08-29T14:01:35-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 14:01:35 keylimepi sudo[2450]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Aug 29 14:01:35 keylimepi sudo[2450]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 14:01:35 keylimepi systemd[1]: mpd.service: Deactivated successfully. Aug 29 14:01:35 keylimepi systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 29 14:01:35 keylimepi systemd[1]: mpd.service: Consumed 5.827s CPU time. Aug 29 14:01:35 keylimepi systemd[1]: mpd.socket: Deactivated successfully. Aug 29 14:01:35 keylimepi systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 29 14:01:35 keylimepi systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 29 14:01:35 keylimepi systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 29 14:01:35 keylimepi systemd[1]: Starting mpd.service - Music Player Daemon... Aug 29 14:01:35 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 29 14:01:35 keylimepi go-librespot[2430]: time="2026-08-29T14:01:35-04:00" level=debug msg="obtained new client token: AAGgGJOU27Ed4TY/zbQAkD4D5sg0eK7o1jOV/u+Sx0TBIVTvb7MQOlmDT31LEom3iZNCXbRmFYxWAzSM/x0GA3CUuNZbGdr1EwDColrAuYkTVUZrO/6j2n6AHQbqxVm6CEEyPajy6qd35fLaiN7oDrDhrrGESIEhfbYgNDJFpPh/QME5ijRn3UIIHT2JjPQ3zTO0mH7YzC6LRnKofPkJP7KfjziENLYxJ8YNv1p4OLs9ntq/Q/XO+wgm" Aug 29 14:01:35 keylimepi volumio[2060]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 14:01:35 keylimepi volumio[2060]: info: [1788026495854] CoreMusicLibrary::Adding element Media Servers Aug 29 14:01:35 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 14:01:35 keylimepi go-librespot[2430]: time="2026-08-29T14:01:35-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 29 14:01:35 keylimepi go-librespot[2430]: time="2026-08-29T14:01:35-04:00" level=debug msg="completed keyexchange" Aug 29 14:01:35 keylimepi go-librespot[2430]: time="2026-08-29T14:01:35-04:00" level=debug msg="completed challenge" Aug 29 14:01:36 keylimepi systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 29 14:01:36 keylimepi sudo[2452]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 29 14:01:36 keylimepi sudo[2452]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 14:01:36 keylimepi sudo[2456]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 29 14:01:36 keylimepi volumio5-onboarding[2459]: time=2026-08-29T14:01:36.105-04:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Aug 29 14:01:36 keylimepi go-librespot[2430]: time="2026-08-29T14:01:36-04:00" level=info msg="authenticated AP" username="dr*****4c" Aug 29 14:01:36 keylimepi sudo[2456]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 14:01:36 keylimepi sudo[2450]: pam_unix(sudo:session): session closed for user root Aug 29 14:01:36 keylimepi volumio[2060]: info: UPNP Browser: Client initialized successfully Aug 29 14:01:36 keylimepi sudo[2452]: pam_unix(sudo:session): session closed for user root Aug 29 14:01:36 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:01:36 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 14:01:36 keylimepi go-librespot[2430]: time="2026-08-29T14:01:36-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 14:01:36 keylimepi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 14:01:36 keylimepi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 14:01:36 keylimepi sudo[2457]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 29 14:01:36 keylimepi sudo[2457]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 29 14:01:36 keylimepi sudo[2457]: pam_unix(sudo:session): session closed for user root Aug 29 14:01:36 keylimepi systemd[1]: mpd.service: Deactivated successfully. Aug 29 14:01:36 keylimepi systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 29 14:01:36 keylimepi systemd[1]: mpd.socket: Deactivated successfully. Aug 29 14:01:36 keylimepi systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 29 14:01:36 keylimepi systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 29 14:01:36 keylimepi volumio[2060]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 29 14:01:36 keylimepi systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 29 14:01:36 keylimepi systemd[1]: Starting mpd.service - Music Player Daemon... Aug 29 14:01:36 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:01:36 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 14:01:36 keylimepi volumio[2060]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 29 14:01:36 keylimepi volumio[2060]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 14:01:36 keylimepi volumio[2060]: info: [1788026496916] CoreMusicLibrary::Adding element Last_100 Aug 29 14:01:36 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 14:01:36 keylimepi volumio[2060]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 14:01:36 keylimepi volumio[2060]: info: [1788026496976] CoreMusicLibrary::Adding element Webradio Aug 29 14:01:36 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 14:01:37 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 29 14:01:37 keylimepi volumio[2060]: info: Initializing BBC Radios Aug 29 14:01:37 keylimepi sudo[2490]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 29 14:01:37 keylimepi sudo[2490]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 29 14:01:37 keylimepi sudo[2490]: pam_unix(sudo:session): session closed for user root Aug 29 14:01:37 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 29 14:01:37 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 14:01:38 keylimepi volumio[2060]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 14:01:38 keylimepi volumio[2060]: info: [1788026498149] CoreMusicLibrary::Adding element SoundCloud Aug 29 14:01:38 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 14:01:38 keylimepi volumio[2060]: Cannot find translation for source SoundCloud Aug 29 14:01:38 keylimepi volumio[2060]: info: Creating Spotify config file Aug 29 14:01:38 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:01:39 keylimepi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Aug 29 14:01:39 keylimepi systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:01:39 keylimepi systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:01:39 keylimepi go-librespot[2510]: go-librespot daemon starting... Aug 29 14:01:39 keylimepi go-librespot[2511]: time="2026-08-29T14:01:39-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 14:01:40 keylimepi go-librespot[2511]: time="2026-08-29T14:01:40-04:00" level=info msg="zeroconf server listening on port 36519" Aug 29 14:01:40 keylimepi go-librespot[2511]: time="2026-08-29T14:01:40-04:00" level=info msg="using built-in mDNS responder" Aug 29 14:01:42 keylimepi mpd[2496]: 2026-08-29T14:01:42 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 29 14:01:42 keylimepi systemd[1]: Started mpd.service - Music Player Daemon. Aug 29 14:01:42 keylimepi sudo[2456]: pam_unix(sudo:session): session closed for user root Aug 29 14:01:42 keylimepi sudo[2442]: pam_unix(sudo:session): session closed for user root Aug 29 14:01:43 keylimepi volumio-remote-updater[703]: [2026-08-29 14:01:43] [connect] Successful connection Aug 29 14:01:43 keylimepi volumio[2060]: info: FusionDsp - CamillaDSP binary found. Aug 29 14:01:43 keylimepi volumio[2060]: info: Loading i18n strings for locale en Aug 29 14:01:43 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Aug 29 14:01:43 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:01:43 keylimepi volumio[2060]: info: FusionDsp - mixtype--------------------- None Aug 29 14:01:43 keylimepi volumio[2060]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 14:01:43 keylimepi volumio[2060]: info: [1788026503713] CoreMusicLibrary::Adding element Pandora Radio Aug 29 14:01:43 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 14:01:43 keylimepi volumio[2060]: Cannot find translation for source SoundCloud Aug 29 14:01:43 keylimepi volumio[2060]: Cannot find translation for source Pandora Radio Aug 29 14:01:43 keylimepi volumio[2060]: info: [1788026503739] ControllerPandora::initialSetup Aug 29 14:01:43 keylimepi volumio[2060]: info: [1788026503745] ControllerPandora::checkPing Aug 29 14:01:43 keylimepi volumio[2060]: info: Volumio Calling Home Aug 29 14:01:44 keylimepi volumio[2060]: info: Preparing to generate the ALSA configuration file Aug 29 14:01:45 keylimepi volumio[2060]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Aug 29 14:01:45 keylimepi volumio[2060]: info: Reading ALSA contributions from plugins. Aug 29 14:01:45 keylimepi volumio[2060]: info: MPD Permissions set Aug 29 14:01:45 keylimepi volumio[2060]: info: MPD Permissions set Aug 29 14:01:45 keylimepi volumio[2060]: info: Volumio called home Aug 29 14:01:45 keylimepi volumio[2060]: info: Spotify config file written Aug 29 14:01:46 keylimepi volumio5-onboarding[2459]: failed to create app: failed to initialize host: failed to create socket connection: could not connect to socket.io server: read tcp 127.0.0.1:38180->127.0.0.1:3000: i/o timeout Aug 29 14:01:46 keylimepi systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Aug 29 14:01:46 keylimepi systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Aug 29 14:01:46 keylimepi sudo[2531]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 29 14:01:46 keylimepi sudo[2531]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 14:01:46 keylimepi systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 1. Aug 29 14:01:46 keylimepi systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 29 14:01:46 keylimepi systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 29 14:01:46 keylimepi volumio5-onboarding[2533]: time=2026-08-29T14:01:46.454-04:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Aug 29 14:01:46 keylimepi systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Aug 29 14:01:46 keylimepi systemd[1]: go-librespot-daemon.service: Killing process 2513 (go-librespot) with signal SIGKILL. Aug 29 14:01:46 keylimepi systemd[1]: go-librespot-daemon.service: Deactivated successfully. Aug 29 14:01:46 keylimepi systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:01:46 keylimepi systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:01:46 keylimepi sudo[2531]: pam_unix(sudo:session): session closed for user root Aug 29 14:01:46 keylimepi go-librespot[2541]: go-librespot daemon starting... Aug 29 14:01:46 keylimepi go-librespot[2542]: time="2026-08-29T14:01:46-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 14:01:46 keylimepi go-librespot[2542]: time="2026-08-29T14:01:46-04:00" level=debug msg="app state loaded" Aug 29 14:01:46 keylimepi go-librespot[2542]: time="2026-08-29T14:01:46-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 14:01:47 keylimepi go-librespot[2542]: time="2026-08-29T14:01:47-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 14:01:47 keylimepi go-librespot[2542]: time="2026-08-29T14:01:47-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 14:01:47 keylimepi go-librespot[2542]: time="2026-08-29T14:01:47-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 14:01:47 keylimepi go-librespot[2542]: time="2026-08-29T14:01:47-04:00" level=info msg="zeroconf server listening on port 44669" Aug 29 14:01:47 keylimepi go-librespot[2542]: time="2026-08-29T14:01:47-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 14:01:47 keylimepi go-librespot[2542]: time="2026-08-29T14:01:47-04:00" level=debug msg="obtained new client token: AAE7RI6fWzvMmLgfCwSS25DMLYXROz6rztm2iIb6ndnTR0G9h0WpWdKeQGf7xyusdZHCLh9nI/v9s4Lra8M8Xry/B83uc40nQ2U9COuBYp1iOXxLLiV2M1HEnkwV2KkO1itwA3PtA0+e9Y1gAVCIXEfkTd+S2NwG4s/Vh9yM6mKb+pJdeyE253cPgd06hHtmUtTxyVmTbFReuKLdsAYLk003Zn6z+CddkZ5K8EFIf7tpigf9TdzIHQL7" Aug 29 14:01:47 keylimepi go-librespot[2542]: time="2026-08-29T14:01:47-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 29 14:01:47 keylimepi go-librespot[2542]: time="2026-08-29T14:01:47-04:00" level=debug msg="completed keyexchange" Aug 29 14:01:47 keylimepi go-librespot[2542]: time="2026-08-29T14:01:47-04:00" level=debug msg="completed challenge" Aug 29 14:01:48 keylimepi go-librespot[2542]: time="2026-08-29T14:01:48-04:00" level=info msg="authenticated AP" username="dr*****4c" Aug 29 14:01:48 keylimepi go-librespot[2542]: time="2026-08-29T14:01:48-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 14:01:48 keylimepi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 14:01:48 keylimepi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 14:01:50 keylimepi volumio[2060]: error: MPD error: The expression evaluated to a falsy value: Aug 29 14:01:50 keylimepi volumio[2060]: assert.ok(self.idling) Aug 29 14:01:50 keylimepi volumio[2060]: error: The expression evaluated to a falsy value: Aug 29 14:01:50 keylimepi volumio[2060]: assert.ok(self.idling) Aug 29 14:01:50 keylimepi volumio[2060]: info: MPD running with PID2496 Aug 29 14:01:50 keylimepi volumio[2060]: ,establishing connection Aug 29 14:01:50 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:01:51 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:01:51 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:01:51 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:01:51 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:01:51 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:01:51 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:01:51 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:01:51 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 14:01:51 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:01:51 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:01:51 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:01:51 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:01:51 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:01:51 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:01:51 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:01:51 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:01:51 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:01:51 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 14:01:51 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:01:51 keylimepi volumio[2060]: info: No need to fix Spotify hosts Aug 29 14:01:51 keylimepi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Aug 29 14:01:51 keylimepi systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:01:51 keylimepi systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:01:51 keylimepi go-librespot[2578]: go-librespot daemon starting... Aug 29 14:01:51 keylimepi go-librespot[2579]: time="2026-08-29T14:01:51-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 14:01:51 keylimepi go-librespot[2579]: time="2026-08-29T14:01:51-04:00" level=debug msg="app state loaded" Aug 29 14:01:51 keylimepi go-librespot[2579]: time="2026-08-29T14:01:51-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 14:01:52 keylimepi go-librespot[2579]: time="2026-08-29T14:01:52-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 14:01:52 keylimepi go-librespot[2579]: time="2026-08-29T14:01:52-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 14:01:52 keylimepi go-librespot[2579]: time="2026-08-29T14:01:52-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 14:01:52 keylimepi go-librespot[2579]: time="2026-08-29T14:01:52-04:00" level=info msg="zeroconf server listening on port 36009" Aug 29 14:01:52 keylimepi go-librespot[2579]: time="2026-08-29T14:01:52-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 14:01:52 keylimepi go-librespot[2579]: time="2026-08-29T14:01:52-04:00" level=debug msg="obtained new client token: AAFvoxJDOXxcEY0hwKv6usHf5JNf0UHtQezk1S16FAWHEIhq40FSPHqsMxLai3IvRDJo+SbmI7spstc2xrTh02GColdTSjh9iYnab3X/rMu4nJHNeqpSSDZPyep+gyzB7CWYM1oSkykxsbpvc05oLEGGoAy5uHR5mUUh0XxPry3RoAexXkaDm3xuDxT0fFGprIUAG9qSKDrZvwlb+t3fNLFXrVMWYMhBH7x85tSbdN1AQ9BuBVcmKi0F" Aug 29 14:01:52 keylimepi go-librespot[2579]: time="2026-08-29T14:01:52-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 29 14:01:52 keylimepi go-librespot[2579]: time="2026-08-29T14:01:52-04:00" level=debug msg="completed keyexchange" Aug 29 14:01:52 keylimepi go-librespot[2579]: time="2026-08-29T14:01:52-04:00" level=debug msg="completed challenge" Aug 29 14:01:52 keylimepi go-librespot[2579]: time="2026-08-29T14:01:52-04:00" level=info msg="authenticated AP" username="dr*****4c" Aug 29 14:01:53 keylimepi go-librespot[2579]: time="2026-08-29T14:01:53-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 14:01:53 keylimepi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 14:01:53 keylimepi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 14:01:54 keylimepi volumio[2060]: error: updateQueue error: null Aug 29 14:01:55 keylimepi volumio[2060]: /usr/bin/mkfifo: cannot create fifo '/tmp/fusiondspfifo': File exists Aug 29 14:01:55 keylimepi volumio[2060]: error: FusionDsp - ----failed to create fusiondspfifo :Error: Command failed: /bin/touch /tmp/fusiondsp_stream_params.log && /bin/chmod 666 /tmp/fusiondsp_stream_params.log && /bin/touch /tmp/camilladsp.log && /bin/chmod 666 /tmp/camilladsp.log && /usr/bin/mkfifo -m 646 /tmp/fusiondspfifo Aug 29 14:01:55 keylimepi volumio[2060]: /usr/bin/mkfifo: cannot create fifo '/tmp/fusiondspfifo': File exists Aug 29 14:01:55 keylimepi volumio[2060]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 29 14:01:55 keylimepi volumio[2060]: info: camilladsp service started and running in background, instance 1 Aug 29 14:01:55 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:01:55 keylimepi volumio[2060]: info: FusionDsp - AAAAAAAAAAAAAA-> 44100 48000 88200 96000 176400 192000 <-AAAAAAAAAAAAA Aug 29 14:01:55 keylimepi volumio[2060]: info: FusionDsp loaded Aug 29 14:01:55 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 14:01:55 keylimepi volumio[2060]: info: FusionDsp - --[object Object] Aug 29 14:01:55 keylimepi volumio[2060]: error: FusionDsp - Socket connection not established Aug 29 14:01:55 keylimepi volumio[2060]: info: FusionDsp - Reporting Fusion DSP Enabled Aug 29 14:01:55 keylimepi volumio[2060]: info: Adding Signal Path Element [object Object] Aug 29 14:01:55 keylimepi volumio[2060]: info: Adding fusiondspeq DSP Signal Path Element Aug 29 14:01:55 keylimepi volumio[2060]: info: FusionDsp - ---- installed callbackRead (debounced 200ms) Aug 29 14:01:55 keylimepi volumio[2060]: info: FusionDsp - PEQ graph server listening on port 10015 Aug 29 14:01:55 keylimepi volumio[2060]: error: MPD error: The expression evaluated to a falsy value: Aug 29 14:01:55 keylimepi volumio[2060]: assert.ok(self.idling) Aug 29 14:01:55 keylimepi volumio[2060]: error: The expression evaluated to a falsy value: Aug 29 14:01:55 keylimepi volumio[2060]: assert.ok(self.idling) Aug 29 14:01:55 keylimepi volumio[2060]: error: MPD error: The expression evaluated to a falsy value: Aug 29 14:01:55 keylimepi volumio[2060]: assert.ok(self.idling) Aug 29 14:01:55 keylimepi volumio[2060]: error: The expression evaluated to a falsy value: Aug 29 14:01:55 keylimepi volumio[2060]: assert.ok(self.idling) Aug 29 14:01:55 keylimepi volumio[2060]: info: New Spotify access tokenBQBpwhFOFb... Aug 29 14:01:55 keylimepi volumio[2060]: info: Spotify credentials grant success - running version from March 24, 2019 Aug 29 14:01:55 keylimepi sudo[2606]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Aug 29 14:01:55 keylimepi sudo[2606]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 14:01:56 keylimepi volumio[2060]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Aug 29 14:01:56 keylimepi volumio[2060]: info: [1788026516039] [Pandora] checkPing: ***LOOKS GOOD, ICE DOWN THE BEERS IN THE COOLER*** Aug 29 14:01:56 keylimepi volumio[2060]: info: [1788026516041] ControllerPandora::checkHTTP Aug 29 14:01:56 keylimepi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Aug 29 14:01:56 keylimepi systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:01:56 keylimepi systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:01:56 keylimepi go-librespot[2608]: go-librespot daemon starting... Aug 29 14:01:56 keylimepi go-librespot[2609]: time="2026-08-29T14:01:56-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 14:01:56 keylimepi go-librespot[2609]: time="2026-08-29T14:01:56-04:00" level=debug msg="app state loaded" Aug 29 14:01:56 keylimepi sudo[2606]: pam_unix(sudo:session): session closed for user root Aug 29 14:01:56 keylimepi go-librespot[2609]: time="2026-08-29T14:01:56-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 14:01:56 keylimepi volumio5-onboarding[2533]: failed to create app: failed to initialize host: failed to create socket connection: could not connect to socket.io server: read tcp 127.0.0.1:56448->127.0.0.1:3000: i/o timeout Aug 29 14:01:56 keylimepi systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Aug 29 14:01:56 keylimepi systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Aug 29 14:01:56 keylimepi systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 2. Aug 29 14:01:56 keylimepi systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 29 14:01:56 keylimepi systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 29 14:01:56 keylimepi volumio[2060]: error: updateQueue error: null Aug 29 14:01:56 keylimepi volumio[2060]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Aug 29 14:01:56 keylimepi volumio5-onboarding[2619]: time=2026-08-29T14:01:56.937-04:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Aug 29 14:01:56 keylimepi volumio[2060]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Aug 29 14:01:56 keylimepi go-librespot[2609]: time="2026-08-29T14:01:56-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 14:01:56 keylimepi go-librespot[2609]: time="2026-08-29T14:01:56-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 14:01:56 keylimepi go-librespot[2609]: time="2026-08-29T14:01:56-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 14:01:56 keylimepi volumio[2060]: error: FusionDsp - Reload WebSocket error: [object Object] Aug 29 14:01:57 keylimepi go-librespot[2609]: time="2026-08-29T14:01:57-04:00" level=info msg="zeroconf server listening on port 45825" Aug 29 14:01:57 keylimepi go-librespot[2609]: time="2026-08-29T14:01:57-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 14:01:57 keylimepi go-librespot[2609]: time="2026-08-29T14:01:57-04:00" level=debug msg="obtained new client token: AAHj59UrHMkQa7W4Ow15f5QC1y4TFpr4b6xMOMyFIMhXv8ziaURZtAXS2trhhRpBq+jhwFo4bmMI28GZ0foBtC18/KpZhIHD2eBam7bwoC5IEplKUPn4UPl1gu2N0ovHOIo8M5P2GTfCKKI3IByVM256+7ATUsuAMGhhlBhUL/iPHKA1UKVSRiDgAZZTaKwQ7JZW1SEvWv7DPjU0iwy3mqRjKbgBcJEIn3SZ/rEzH3z7//x/bHBDiA==" Aug 29 14:01:57 keylimepi go-librespot[2609]: time="2026-08-29T14:01:57-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 29 14:01:57 keylimepi volumio[2060]: info: Starting Shairport Sync Aug 29 14:01:57 keylimepi go-librespot[2609]: time="2026-08-29T14:01:57-04:00" level=debug msg="completed keyexchange" Aug 29 14:01:57 keylimepi go-librespot[2609]: time="2026-08-29T14:01:57-04:00" level=debug msg="completed challenge" Aug 29 14:01:57 keylimepi volumio[2060]: info: Starting Shairport Sync Aug 29 14:01:57 keylimepi volumio[2060]: info: Starting Shairport Sync Aug 29 14:01:57 keylimepi go-librespot[2609]: time="2026-08-29T14:01:57-04:00" level=info msg="authenticated AP" username="dr*****4c" Aug 29 14:01:57 keylimepi sudo[2629]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 29 14:01:57 keylimepi sudo[2629]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 14:01:57 keylimepi go-librespot[2609]: time="2026-08-29T14:01:57-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 14:01:57 keylimepi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 14:01:57 keylimepi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 14:01:57 keylimepi sudo[2637]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 29 14:01:57 keylimepi sudo[2631]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 29 14:01:57 keylimepi sudo[2631]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 14:01:57 keylimepi sudo[2637]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 14:01:57 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Aug 29 14:01:57 keylimepi volumio[2060]: info: go-librespot daemon successfully initialized Aug 29 14:01:58 keylimepi systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 29 14:01:58 keylimepi systemd[1]: shairport-sync.service: Deactivated successfully. Aug 29 14:01:58 keylimepi systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 29 14:01:58 keylimepi systemd[1]: shairport-sync.service: Consumed 2.757s CPU time. Aug 29 14:01:58 keylimepi systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 29 14:01:58 keylimepi sudo[2637]: pam_unix(sudo:session): session closed for user root Aug 29 14:01:58 keylimepi systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 29 14:01:58 keylimepi systemd[1]: shairport-sync.service: Deactivated successfully. Aug 29 14:01:58 keylimepi systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 29 14:01:58 keylimepi sudo[2631]: pam_unix(sudo:session): session closed for user root Aug 29 14:01:58 keylimepi volumio-remote-updater[703]: [2026-08-29 14:01:58] [connect] Successful connection Aug 29 14:01:58 keylimepi systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 29 14:01:58 keylimepi sudo[2629]: pam_unix(sudo:session): session closed for user root Aug 29 14:01:58 keylimepi volumio[2060]: info: Asound.conf file unchanged, so no further update is needed Aug 29 14:01:58 keylimepi volumio[2060]: info: Output device has changed, restarting MPD Aug 29 14:01:58 keylimepi sudo[2668]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 29 14:01:58 keylimepi sudo[2668]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 14:01:58 keylimepi volumio[2060]: info: Output device has changed, restarting Shairport Sync Aug 29 14:01:58 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:01:58 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 14:01:58 keylimepi sudo[2668]: pam_unix(sudo:session): session closed for user root Aug 29 14:01:58 keylimepi sudo[2670]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 29 14:01:58 keylimepi sudo[2670]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 14:01:58 keylimepi volumio[2060]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 29 14:01:59 keylimepi systemd[1]: Stopping mpd.service - Music Player Daemon... Aug 29 14:01:59 keylimepi systemd[1]: mpd.service: Deactivated successfully. Aug 29 14:01:59 keylimepi systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 29 14:01:59 keylimepi systemd[1]: mpd.service: Consumed 5.444s CPU time. Aug 29 14:01:59 keylimepi systemd[1]: mpd.socket: Deactivated successfully. Aug 29 14:01:59 keylimepi systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 29 14:01:59 keylimepi systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 29 14:01:59 keylimepi volumio[2060]: info: Shairport-Sync Started Aug 29 14:01:59 keylimepi systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 29 14:01:59 keylimepi volumio[2060]: Error adding Membership: Error: addMembership EINVAL Aug 29 14:01:59 keylimepi volumio[2060]: info: Shairport-Sync Started Aug 29 14:01:59 keylimepi volumio[2060]: info: Shairport-Sync Started Aug 29 14:01:59 keylimepi systemd[1]: Starting mpd.service - Music Player Daemon... Aug 29 14:01:59 keylimepi sudo[2678]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 29 14:01:59 keylimepi sudo[2678]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 29 14:01:59 keylimepi sudo[2678]: pam_unix(sudo:session): session closed for user root Aug 29 14:01:59 keylimepi volumio[2060]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 11 Aug 29 14:02:00 keylimepi volumio[2060]: info: MPD Permissions set Aug 29 14:02:00 keylimepi volumio[2060]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 11 Aug 29 14:02:00 keylimepi volumio[2060]: info: Received Get System Info Aug 29 14:02:00 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 14:02:00 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 14:02:00 keylimepi volumio[2060]: info: Discovery: Getting this device information Aug 29 14:02:00 keylimepi volumio[2060]: info: CoreCommandRouter::volumioGetState Aug 29 14:02:00 keylimepi volumio[2060]: info: CorePlayQueue::getTrack 0 Aug 29 14:02:00 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 14:02:00 keylimepi volumio5-onboarding[2619]: time=2026-08-29T14:02:00.275-04:00 level=INFO msg="system info for e8d25ead96025269b496a1c0099f22ee" deviceName=KeyLimePi deviceVariant=volumio deviceModel= softwareVersion=4.119 Aug 29 14:02:00 keylimepi volumio5-onboarding[2619]: time=2026-08-29T14:02:00.306-04:00 level=INFO msg="bootstrapping state" hasInternet=true Aug 29 14:02:00 keylimepi volumio[2060]: info: Received Get System Info Aug 29 14:02:00 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 14:02:00 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 14:02:00 keylimepi volumio[2060]: info: Discovery: Getting this device information Aug 29 14:02:00 keylimepi volumio[2060]: info: CoreCommandRouter::volumioGetState Aug 29 14:02:00 keylimepi volumio[2060]: info: CorePlayQueue::getTrack 0 Aug 29 14:02:00 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 14:02:00 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:02:00 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:02:00 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:02:00 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:02:00 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:02:00 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:02:00 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:02:00 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:02:00 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 14:02:00 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 14:02:00 keylimepi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Aug 29 14:02:00 keylimepi systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:02:00 keylimepi systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:02:00 keylimepi go-librespot[2687]: go-librespot daemon starting... Aug 29 14:02:00 keylimepi volumio[2060]: info: Initializing connection to go-librespot Websocket Aug 29 14:02:01 keylimepi go-librespot[2688]: time="2026-08-29T14:02:01-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 14:02:01 keylimepi go-librespot[2688]: time="2026-08-29T14:02:01-04:00" level=debug msg="app state loaded" Aug 29 14:02:01 keylimepi go-librespot[2688]: time="2026-08-29T14:02:01-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 14:02:01 keylimepi go-librespot[2688]: time="2026-08-29T14:02:01-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 14:02:01 keylimepi go-librespot[2688]: time="2026-08-29T14:02:01-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 14:02:01 keylimepi go-librespot[2688]: time="2026-08-29T14:02:01-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 14:02:01 keylimepi go-librespot[2688]: time="2026-08-29T14:02:01-04:00" level=info msg="zeroconf server listening on port 41609" Aug 29 14:02:01 keylimepi go-librespot[2688]: time="2026-08-29T14:02:01-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 14:02:02 keylimepi volumio-remote-updater[703]: [2026-08-29 14:02:01] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1788026518 101 Aug 29 14:02:02 keylimepi go-librespot[2688]: time="2026-08-29T14:02:02-04:00" level=debug msg="obtained new client token: AAFsEEJzJIljap6Tj6lKnLTDzIDfcbU8rOB5WwiVOupIvdOX8xqv+OqT9GsVvcjPDsA6OZibxnoI7LyMMhXBu7dGs4CNNWM3dhIYjNCsAbjhDGHQ8rOz8PXOTz6pkiRmHwJmMZRjEbSWvkD94gFfDz/IJAO2HnKSsmiCeCKcEjqGaURxCZe2gNhAaLuSOIpBglsDi/V7cphRhtUOxa6yfRl33QhqukYp0DHch/j2kLgqXk4isHn7SQ==" Aug 29 14:02:02 keylimepi volumio[2060]: 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: 12 Aug 29 14:02:02 keylimepi go-librespot[2688]: time="2026-08-29T14:02:02-04:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.255.62:4070: connect: connection refused" Aug 29 14:02:02 keylimepi go-librespot[2688]: time="2026-08-29T14:02:02-04:00" level=debug msg="connected to ap-gue1.spotify.com:443" Aug 29 14:02:02 keylimepi volumio[2060]: info: Starting Shairport Sync Aug 29 14:02:02 keylimepi go-librespot[2688]: time="2026-08-29T14:02:02-04:00" level=debug msg="completed keyexchange" Aug 29 14:02:02 keylimepi go-librespot[2688]: time="2026-08-29T14:02:02-04:00" level=debug msg="completed challenge" Aug 29 14:02:02 keylimepi go-librespot[2688]: time="2026-08-29T14:02:02-04:00" level=info msg="authenticated AP" username="dr*****4c" Aug 29 14:02:02 keylimepi volumio[2060]: SPOTIFY: User informations: {"account_id":"FYzro3IJIE","country":"US","display_name":"draketr4c","email":"draketr4c@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/draketr4c"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/draketr4c","id":"draketr4c","images":[],"product":"premium","type":"user","uri":"spotify:user:draketr4c"} Aug 29 14:02:02 keylimepi volumio[2060]: info: Spotify Successfully logged in Aug 29 14:02:02 keylimepi go-librespot[2688]: time="2026-08-29T14:02:02-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 14:02:02 keylimepi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 14:02:02 keylimepi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 14:02:02 keylimepi sudo[2699]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 29 14:02:02 keylimepi sudo[2699]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 14:02:02 keylimepi volumio[2060]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 14:02:02 keylimepi volumio[2060]: info: [1788026522723] CoreMusicLibrary::Adding element Spotify Aug 29 14:02:02 keylimepi volumio[2060]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 14:02:02 keylimepi volumio[2060]: Cannot find translation for source SoundCloud Aug 29 14:02:02 keylimepi volumio[2060]: Cannot find translation for source Pandora Radio Aug 29 14:02:02 keylimepi volumio[2060]: Cannot find translation for source Spotify Aug 29 14:02:03 keylimepi systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 29 14:02:03 keylimepi systemd[1]: shairport-sync.service: Deactivated successfully. Aug 29 14:02:03 keylimepi systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 29 14:02:03 keylimepi systemd[1]: shairport-sync.service: Consumed 1.439s CPU time. Aug 29 14:02:03 keylimepi systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 29 14:02:03 keylimepi sudo[2699]: pam_unix(sudo:session): session closed for user root Aug 29 14:02:03 keylimepi volumio[2060]: info: Error connecting to go-librespot Websocket: Error: socket hang up Aug 29 14:02:04 keylimepi volumio[2060]: info: CoreCommandRouter::volumioGetState Aug 29 14:02:04 keylimepi volumio[2060]: info: CorePlayQueue::getTrack 0 Aug 29 14:02:04 keylimepi volumio[2060]: info: Shairport-Sync Started Aug 29 14:02:05 keylimepi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Aug 29 14:02:05 keylimepi systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:02:05 keylimepi mpd[2680]: 2026-08-29T14:02:05 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 29 14:02:05 keylimepi systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:02:05 keylimepi systemd[1]: Started mpd.service - Music Player Daemon. Aug 29 14:02:05 keylimepi go-librespot[2717]: go-librespot daemon starting... Aug 29 14:02:05 keylimepi sudo[2670]: pam_unix(sudo:session): session closed for user root Aug 29 14:02:05 keylimepi go-librespot[2720]: time="2026-08-29T14:02:05-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 14:02:05 keylimepi go-librespot[2720]: time="2026-08-29T14:02:05-04:00" level=debug msg="app state loaded" Aug 29 14:02:06 keylimepi go-librespot[2720]: time="2026-08-29T14:02:06-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 14:02:06 keylimepi go-librespot[2720]: time="2026-08-29T14:02:06-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Aug 29 14:02:06 keylimepi go-librespot[2720]: time="2026-08-29T14:02:06-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Aug 29 14:02:06 keylimepi go-librespot[2720]: time="2026-08-29T14:02:06-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Aug 29 14:02:06 keylimepi go-librespot[2720]: time="2026-08-29T14:02:06-04:00" level=info msg="zeroconf server listening on port 36715" Aug 29 14:02:06 keylimepi go-librespot[2720]: time="2026-08-29T14:02:06-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 14:02:06 keylimepi go-librespot[2720]: time="2026-08-29T14:02:06-04:00" level=debug msg="obtained new client token: AAHKTJhm/2dGnJl7OHl1YsgAny5q3GlKsoPv22zg8b9CtVpnzxxWZA0QOzcYLww9GOizSqCc113snCq2RyY28TzKcp2VqoNOKhd8+Irjok1td5kYDgLPLehJlb3ma6gnv+MlZOeQV5Tm9duCNMO1cC/K+BuM5E6hWTQN2aYWXW2GVsnyxYBAUQgQzdxlJ7GU/EQZrEHRG2NPU2pQsNp5slBe0qRB8HZMvN3Qb9eWsd+xNJKAnMCcYmWv" Aug 29 14:02:06 keylimepi volumio[2060]: info: Initializing connection to go-librespot Websocket Aug 29 14:02:06 keylimepi go-librespot[2720]: time="2026-08-29T14:02:06-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 29 14:02:07 keylimepi volumio[2060]: info: [1788026527068] [Pandora] checkHTTP: ***CRACK THE BEERS WE HAVE INTERNET*** Aug 29 14:02:07 keylimepi volumio[2060]: info: [1788026527069] ControllerPandora::initializeMQTT Aug 29 14:02:07 keylimepi volumio[2060]: info: [1788026527069] [Pandora] initializeMQTT: MQTT is not enabled in Plugin Configuration Aug 29 14:02:07 keylimepi volumio[2060]: info: [1788026527071] ControllerPandora::PandoraHandler::init Aug 29 14:02:07 keylimepi volumio[2060]: info: [1788026527071] ControllerPandora::PandoraHandler::loadErrorCodes Aug 29 14:02:07 keylimepi volumio[2060]: info: [1788026527074] ControllerPandora::validateAndSetAccountOptions Aug 29 14:02:07 keylimepi volumio[2060]: info: [1788026527075] ControllerPandora::PandoraHandler::setAccountOptions Aug 29 14:02:07 keylimepi volumio[2060]: info: [1788026527086] ControllerPandora::flushPandora Aug 29 14:02:07 keylimepi volumio[2060]: info: CorePlayQueue::getQueue Aug 29 14:02:07 keylimepi volumio[2060]: info: CorePlayQueue::clearPlayQueue Aug 29 14:02:07 keylimepi volumio[2060]: info: CorePlayQueue::saveQueue Aug 29 14:02:07 keylimepi volumio[2060]: info: CoreCommandRouter::volumioPushQueue Aug 29 14:02:07 keylimepi volumio[2060]: info: [1788026527114] [Pandora] PreventAuthTimeout::init: Timer loaded Aug 29 14:02:07 keylimepi volumio[2060]: info: [1788026527115] [Pandora] PreventAuthTimeout::init: Interval set to 10800000 ms Aug 29 14:02:07 keylimepi volumio[2060]: info: [1788026527115] [Pandora] PreventAuthTimeout::init: Starting delayed timer after next interval Aug 29 14:02:07 keylimepi volumio[2060]: info: [1788026527126] ControllerPandora::PandoraHandler::pandoraLoginAndGetStations Aug 29 14:02:07 keylimepi volumio[2060]: error: updateQueue error: null Aug 29 14:02:07 keylimepi go-librespot[2720]: time="2026-08-29T14:02:07-04:00" level=debug msg="new websocket client" Aug 29 14:02:07 keylimepi go-librespot[2720]: time="2026-08-29T14:02:07-04:00" level=debug msg="completed keyexchange" Aug 29 14:02:07 keylimepi go-librespot[2720]: time="2026-08-29T14:02:07-04:00" level=debug msg="completed challenge" Aug 29 14:02:07 keylimepi volumio[2060]: info: Connection to go-librespot Websocket established Aug 29 14:02:07 keylimepi go-librespot[2720]: time="2026-08-29T14:02:07-04:00" level=info msg="authenticated AP" username="dr*****4c" Aug 29 14:02:07 keylimepi go-librespot[2720]: time="2026-08-29T14:02:07-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 14:02:07 keylimepi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 14:02:07 keylimepi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 14:02:08 keylimepi volumio[2060]: info: Connection to go-librespot Websocket closed Aug 29 14:02:10 keylimepi volumio[2060]: info: [1788026530415] [Pandora] PandoraHandler::pandoraLoginAndGetStations::pandoraLogin: [<=- Logged in to Pandora Servers -=>] Aug 29 14:02:10 keylimepi volumio[2060]: info: [1788026530557] [Pandora] validateAndSetAccountOptions: ***DEBUG*** self.loggedIn: true Aug 29 14:02:10 keylimepi volumio[2060]: info: [1788026530559] [Pandora] ExpireOldTracks::init: Timer loaded Aug 29 14:02:10 keylimepi volumio[2060]: info: [1788026530560] [Pandora] ExpireOldTracks::init: Interval set to 300000 ms Aug 29 14:02:10 keylimepi volumio[2060]: info: [1788026530560] [Pandora] ExpireOldTracks::init: Starting delayed timer after next interval Aug 29 14:02:10 keylimepi volumio[2060]: info: [1788026530562] ControllerPandora::PandoraHandler::fillStationData Aug 29 14:02:10 keylimepi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Aug 29 14:02:10 keylimepi systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:02:10 keylimepi systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:02:10 keylimepi go-librespot[2743]: go-librespot daemon starting... Aug 29 14:02:10 keylimepi volumio[2060]: info: Getting Spotify volume Aug 29 14:02:11 keylimepi go-librespot[2744]: time="2026-08-29T14:02:11-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 14:02:11 keylimepi go-librespot[2744]: time="2026-08-29T14:02:11-04:00" level=debug msg="app state loaded" Aug 29 14:02:11 keylimepi go-librespot[2744]: time="2026-08-29T14:02:11-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 14:02:11 keylimepi volumio[2060]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 29 14:02:11 keylimepi volumio[2060]: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 29 14:02:11 keylimepi volumio[2060]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Aug 29 14:02:11 keylimepi volumio[2060]: errno: -111, Aug 29 14:02:11 keylimepi volumio[2060]: code: 'ECONNREFUSED', Aug 29 14:02:11 keylimepi volumio[2060]: syscall: 'connect', Aug 29 14:02:11 keylimepi volumio[2060]: address: '127.0.0.1', Aug 29 14:02:11 keylimepi volumio[2060]: port: 9879, Aug 29 14:02:11 keylimepi volumio[2060]: response: undefined Aug 29 14:02:11 keylimepi volumio[2060]: } Aug 29 14:02:11 keylimepi volumio[2060]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 29 14:02:11 keylimepi go-librespot[2744]: time="2026-08-29T14:02:11-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 14:02:11 keylimepi go-librespot[2744]: time="2026-08-29T14:02:11-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 14:02:11 keylimepi go-librespot[2744]: time="2026-08-29T14:02:11-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 14:02:11 keylimepi go-librespot[2744]: time="2026-08-29T14:02:11-04:00" level=info msg="zeroconf server listening on port 43667" Aug 29 14:02:11 keylimepi go-librespot[2744]: time="2026-08-29T14:02:11-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 14:02:11 keylimepi go-librespot[2744]: time="2026-08-29T14:02:11-04:00" level=debug msg="obtained new client token: AAEKisqoVTujGqGa35y2GDsDLG3239bWWEJcJYuzAGUyqkbDSoU3rIzB22tShQyiuAoiFcvSUHcPedWQrdo+6GtrldAqoKZFsJ//qpOi7yTuGk2HOrGx1ff0EpaaruYoYtOIKrtMEB1oiTjqkkD6iANctqxpJxhn+AvjpaUEpqts4oGPszkufBcOoBGXD8nRFRX2rIFDE+vJ1B+GoDO++rxBRDDNE6GDymjoQyiDimaEDaH7ugMIgnpO" Aug 29 14:02:11 keylimepi go-librespot[2744]: time="2026-08-29T14:02:11-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 29 14:02:12 keylimepi go-librespot[2744]: time="2026-08-29T14:02:12-04:00" level=debug msg="completed keyexchange" Aug 29 14:02:12 keylimepi go-librespot[2744]: time="2026-08-29T14:02:12-04:00" level=debug msg="completed challenge" Aug 29 14:02:12 keylimepi go-librespot[2744]: time="2026-08-29T14:02:12-04:00" level=info msg="authenticated AP" username="dr*****4c" Aug 29 14:02:12 keylimepi go-librespot[2744]: time="2026-08-29T14:02:12-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 14:02:12 keylimepi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 14:02:12 keylimepi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 14:02:15 keylimepi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Aug 29 14:02:15 keylimepi systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:02:15 keylimepi systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:02:15 keylimepi go-librespot[2765]: go-librespot daemon starting... Aug 29 14:02:15 keylimepi go-librespot[2766]: time="2026-08-29T14:02:15-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 14:02:15 keylimepi go-librespot[2766]: time="2026-08-29T14:02:15-04:00" level=debug msg="app state loaded" Aug 29 14:02:15 keylimepi go-librespot[2766]: time="2026-08-29T14:02:15-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 14:02:16 keylimepi go-librespot[2766]: time="2026-08-29T14:02:16-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 14:02:16 keylimepi go-librespot[2766]: time="2026-08-29T14:02:16-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 14:02:16 keylimepi go-librespot[2766]: time="2026-08-29T14:02:16-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 14:02:16 keylimepi go-librespot[2766]: time="2026-08-29T14:02:16-04:00" level=info msg="zeroconf server listening on port 35457" Aug 29 14:02:16 keylimepi go-librespot[2766]: time="2026-08-29T14:02:16-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 14:02:16 keylimepi go-librespot[2766]: time="2026-08-29T14:02:16-04:00" level=debug msg="obtained new client token: AAGLo4aVv3a7VgJ5BiYtMD7kF54HaAfL5p1zeuNtcsYJ4Y6KXrPCa3XqTeuZbo7TNCCAm0bqRlSuBwQO+4n6a/H3K3U2u2yRBZmfsMlRN/ZWs7v9Ca7/esCprHQwzQmHtAhDED3FzVlTeICphbDEFMorOEHvRP36KoVKUch0wmCHjRyq8k68z7FYFZOTWdeLDFFO3YmZG1wDq31uV24dIBt7fp5ybQRlAqETHgCfeFYKXHnZjXCPl7At" Aug 29 14:02:16 keylimepi go-librespot[2766]: time="2026-08-29T14:02:16-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 29 14:02:16 keylimepi go-librespot[2766]: time="2026-08-29T14:02:16-04:00" level=debug msg="completed keyexchange" Aug 29 14:02:16 keylimepi go-librespot[2766]: time="2026-08-29T14:02:16-04:00" level=debug msg="completed challenge" Aug 29 14:02:16 keylimepi go-librespot[2766]: time="2026-08-29T14:02:16-04:00" level=info msg="authenticated AP" username="dr*****4c" Aug 29 14:02:16 keylimepi go-librespot[2766]: time="2026-08-29T14:02:16-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 14:02:16 keylimepi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 14:02:16 keylimepi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 14:02:20 keylimepi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Aug 29 14:02:20 keylimepi systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:02:20 keylimepi systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:02:20 keylimepi go-librespot[2790]: go-librespot daemon starting... Aug 29 14:02:20 keylimepi go-librespot[2791]: time="2026-08-29T14:02:20-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 14:02:20 keylimepi go-librespot[2791]: time="2026-08-29T14:02:20-04:00" level=debug msg="app state loaded" Aug 29 14:02:20 keylimepi go-librespot[2791]: time="2026-08-29T14:02:20-04:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 29 14:02:20 keylimepi go-librespot[2791]: time="2026-08-29T14:02:20-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 14:02:20 keylimepi go-librespot[2791]: time="2026-08-29T14:02:20-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 14:02:20 keylimepi go-librespot[2791]: time="2026-08-29T14:02:20-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 14:02:20 keylimepi go-librespot[2791]: time="2026-08-29T14:02:20-04:00" level=info msg="zeroconf server listening on port 38871" Aug 29 14:02:20 keylimepi go-librespot[2791]: time="2026-08-29T14:02:20-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 29 14:02:21 keylimepi go-librespot[2791]: time="2026-08-29T14:02:21-04:00" level=debug msg="obtained new client token: AAFjKHGlYVhrwWVSwxsHAx0ysdOhVGYh3eCxLVZLt91lyI88ZBq7faGok5lvTK10D6AjevOD7p2jpDp8RI9ljbcU+XMU7pA6OwV52s/hWKQ42iLeMmAR07yPXPr9fQH4QGh4nA1ZIA3ErnNvJZUXtqX9tFiigzAWGrECHqFSDkJ75Wh+bBBVg+I9QesBiDjNI18yybydJ41lgaYXMRlPZ+vtshnvqQm/8Z3w2j2mU5IHzdHVQhWakw==" Aug 29 14:02:21 keylimepi go-librespot[2791]: time="2026-08-29T14:02:21-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Aug 29 14:02:21 keylimepi go-librespot[2791]: time="2026-08-29T14:02:21-04:00" level=debug msg="completed keyexchange" Aug 29 14:02:21 keylimepi go-librespot[2791]: time="2026-08-29T14:02:21-04:00" level=debug msg="completed challenge" Aug 29 14:02:21 keylimepi go-librespot[2791]: time="2026-08-29T14:02:21-04:00" level=info msg="authenticated AP" username="dr*****4c" Aug 29 14:02:21 keylimepi go-librespot[2791]: time="2026-08-29T14:02:21-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 29 14:02:21 keylimepi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 29 14:02:21 keylimepi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 29 14:02:23 keylimepi sudo[2802]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-29 14:01' Aug 29 14:02:23 keylimepi sudo[2802]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 29 14:02:24 keylimepi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Aug 29 14:02:24 keylimepi systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:02:24 keylimepi systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 29 14:02:24 keylimepi go-librespot[2804]: go-librespot daemon starting... Aug 29 14:02:24 keylimepi go-librespot[2805]: time="2026-08-29T14:02:24-04:00" level=info msg="running go-librespot 0.7.1" Aug 29 14:02:24 keylimepi go-librespot[2805]: time="2026-08-29T14:02:24-04:00" level=debug msg="app state loaded" Aug 29 14:02:25 keylimepi go-librespot[2805]: time="2026-08-29T14:02:25-04:00" level=info msg="api server listening on 127.0.0.1:9879" 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"