Sep 01 00:12:00 stefans-speaker volumio[2993]: error: MyVolumio Plugin failed to authenticate in a timely fashion Sep 01 00:12:00 stefans-speaker volumio[2993]: info: Completed starting MyVolumio Plugin Sep 01 00:12:00 stefans-speaker volumio[2993]: [Metrics] CommandRouter: 44s 452.87ms Sep 01 00:12:00 stefans-speaker volumio[2993]: info: CoreCommandRouter::volumiosetStartupVolume Sep 01 00:12:00 stefans-speaker volumio[2993]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:12:00 stefans-speaker volumio[2993]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:12:00 stefans-speaker volumio[2993]: info: CoreCommandRouter::Close All Modals sent Sep 01 00:12:00 stefans-speaker volumio[2993]: info: CoreCommandRouter::Close All Modals sent Sep 01 00:12:01 stefans-speaker volumio[2993]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Sep 01 00:12:01 stefans-speaker volumio[2993]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Sep 01 00:12:01 stefans-speaker volumio[2993]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Sep 01 00:12:01 stefans-speaker volumio[2993]: info: Initializing connection to go-librespot Websocket Sep 01 00:12:01 stefans-speaker volumio[2993]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 00:12:02 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Sep 01 00:12:02 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:12:02 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:12:02 stefans-speaker go-librespot[3464]: go-librespot daemon starting... Sep 01 00:12:02 stefans-speaker go-librespot[3465]: time="2026-09-01T00:12:02+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:12:02 stefans-speaker go-librespot[3465]: time="2026-09-01T00:12:02+02:00" level=debug msg="app state loaded" Sep 01 00:12:02 stefans-speaker go-librespot[3465]: time="2026-09-01T00:12:02+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:12:02 stefans-speaker go-librespot[3465]: time="2026-09-01T00:12:02+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 00:12:02 stefans-speaker go-librespot[3465]: time="2026-09-01T00:12:02+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 01 00:12:02 stefans-speaker go-librespot[3465]: time="2026-09-01T00:12:02+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 01 00:12:02 stefans-speaker go-librespot[3465]: time="2026-09-01T00:12:02+02:00" level=info msg="zeroconf server listening on port 43229" Sep 01 00:12:02 stefans-speaker go-librespot[3465]: time="2026-09-01T00:12:02+02:00" level=debug msg="obtained new client token: AAHLG+/0+U8hJEz2nM29H6Fh8keihR3X9WM+ksOH8Bx7wq+P4tSKuGjoSsMomVjAzF31biV/O0Ff4mw7Gx7rDwaJny4fMFqF/SU9ynm5XW9tPzkaRr8GWa4yKjW6i21vno1eh3HNqTCXKXpRn7V66SGCvpnQXxYc5J7rhmX2SILEPfvFktCYWoVQRs14cdBFpA3CnkZd0Rwjjw8tI8qzhl9kGGUpboX22qhbxbYQzeIjVArxbiD1sp+EkGg=" Sep 01 00:12:02 stefans-speaker go-librespot[3465]: time="2026-09-01T00:12:02+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 00:12:02 stefans-speaker go-librespot[3465]: time="2026-09-01T00:12:02+02:00" level=debug msg="completed keyexchange" Sep 01 00:12:02 stefans-speaker go-librespot[3465]: time="2026-09-01T00:12:02+02:00" level=debug msg="completed challenge" Sep 01 00:12:02 stefans-speaker go-librespot[3465]: time="2026-09-01T00:12:02+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:12:02 stefans-speaker go-librespot[3465]: time="2026-09-01T00:12:02+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 00:12:02 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:12:02 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:12:04 stefans-speaker volumio[2993]: info: Initializing connection to go-librespot Websocket Sep 01 00:12:04 stefans-speaker volumio[2993]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 00:12:05 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Sep 01 00:12:05 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:12:05 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:12:05 stefans-speaker go-librespot[3472]: go-librespot daemon starting... Sep 01 00:12:05 stefans-speaker go-librespot[3473]: time="2026-09-01T00:12:05+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:12:05 stefans-speaker go-librespot[3473]: time="2026-09-01T00:12:05+02:00" level=debug msg="app state loaded" Sep 01 00:12:05 stefans-speaker go-librespot[3473]: time="2026-09-01T00:12:05+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:12:06 stefans-speaker go-librespot[3473]: time="2026-09-01T00:12:06+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 00:12:06 stefans-speaker go-librespot[3473]: time="2026-09-01T00:12:06+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 01 00:12:06 stefans-speaker go-librespot[3473]: time="2026-09-01T00:12:06+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 01 00:12:06 stefans-speaker go-librespot[3473]: time="2026-09-01T00:12:06+02:00" level=info msg="zeroconf server listening on port 44527" Sep 01 00:12:06 stefans-speaker go-librespot[3473]: time="2026-09-01T00:12:06+02:00" level=debug msg="obtained new client token: AAG+Xva/uGqWN9p8V5STENElyhRBHcuvyFzotaamVxx/dKcfrx5+VfWYQLvqolcGkn9m83qG9/KkQKmLLbXJyHzo3dfrt4P4eQgHZWmk4k+32o+bFtOPH9isOPs2RMbK6BjskXjO1xy3UloHP4iMd2aeigsQDKmt4uBHxe68M5fsKaqU4/l0z8ZLOg1Yt7M8fa2F+BbtiuwxlbgY+x+cpTKdFUBL48fvmpfiWBn7BapqOdUlpoO1gDr4" Sep 01 00:12:06 stefans-speaker go-librespot[3473]: time="2026-09-01T00:12:06+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 00:12:06 stefans-speaker go-librespot[3473]: time="2026-09-01T00:12:06+02:00" level=debug msg="completed keyexchange" Sep 01 00:12:06 stefans-speaker go-librespot[3473]: time="2026-09-01T00:12:06+02:00" level=debug msg="completed challenge" Sep 01 00:12:06 stefans-speaker go-librespot[3473]: time="2026-09-01T00:12:06+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:12:06 stefans-speaker go-librespot[3473]: time="2026-09-01T00:12:06+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 00:12:06 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:12:06 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:12:07 stefans-speaker volumio[2993]: info: BOOT COMPLETED Sep 01 00:12:07 stefans-speaker volumio[2993]: info: Initializing connection to go-librespot Websocket Sep 01 00:12:07 stefans-speaker volumio[2993]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 00:12:09 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Sep 01 00:12:09 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:12:09 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:12:09 stefans-speaker go-librespot[3494]: go-librespot daemon starting... Sep 01 00:12:09 stefans-speaker go-librespot[3495]: time="2026-09-01T00:12:09+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:12:09 stefans-speaker go-librespot[3495]: time="2026-09-01T00:12:09+02:00" level=debug msg="app state loaded" Sep 01 00:12:09 stefans-speaker go-librespot[3495]: time="2026-09-01T00:12:09+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:12:09 stefans-speaker go-librespot[3495]: time="2026-09-01T00:12:09+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Sep 01 00:12:09 stefans-speaker go-librespot[3495]: time="2026-09-01T00:12:09+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Sep 01 00:12:09 stefans-speaker go-librespot[3495]: time="2026-09-01T00:12:09+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Sep 01 00:12:09 stefans-speaker go-librespot[3495]: time="2026-09-01T00:12:09+02:00" level=info msg="zeroconf server listening on port 34503" Sep 01 00:12:09 stefans-speaker go-librespot[3495]: time="2026-09-01T00:12:09+02:00" level=debug msg="obtained new client token: AAFVPgbJjXR5r9IbFpxJf6e4zoizWRH438L04yzBMLc2hlHd2NW46OvL8t4OtZn1zqoom7ibtEL0i3H4WroxeuGpf1zUd4RcdcRg0SQ86EiV1rgReXQo2gev0uBihlpB99bAE+7Th9/dJfdmTyD7Q2jmiPDz4HYxoWDsJmj29YG2G9/6vugfDX2GDJLWdq+kIBgQQ2om+MwusS6d+QLuplDPi5E4SVjeH2jubQuCsiIDFVv/Kszx8zWHQcA=" Sep 01 00:12:10 stefans-speaker go-librespot[3495]: time="2026-09-01T00:12:10+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 00:12:10 stefans-speaker go-librespot[3495]: time="2026-09-01T00:12:10+02:00" level=debug msg="completed keyexchange" Sep 01 00:12:10 stefans-speaker go-librespot[3495]: time="2026-09-01T00:12:10+02:00" level=debug msg="completed challenge" Sep 01 00:12:10 stefans-speaker go-librespot[3495]: time="2026-09-01T00:12:10+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:12:10 stefans-speaker volumio[2993]: info: Initializing connection to go-librespot Websocket Sep 01 00:12:10 stefans-speaker go-librespot[3495]: time="2026-09-01T00:12:10+02:00" level=debug msg="new websocket client" Sep 01 00:12:10 stefans-speaker volumio[2993]: info: Connection to go-librespot Websocket established Sep 01 00:12:10 stefans-speaker go-librespot[3495]: time="2026-09-01T00:12:10+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 00:12:10 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:12:10 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:12:10 stefans-speaker volumio[2993]: info: Connection to go-librespot Websocket closed Sep 01 00:12:13 stefans-speaker volumio[2993]: info: Getting Spotify volume Sep 01 00:12:13 stefans-speaker volumio[2993]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 01 00:12:13 stefans-speaker volumio[2993]: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 00:12:13 stefans-speaker volumio[2993]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Sep 01 00:12:13 stefans-speaker volumio[2993]: errno: -111, Sep 01 00:12:13 stefans-speaker volumio[2993]: code: 'ECONNREFUSED', Sep 01 00:12:13 stefans-speaker volumio[2993]: syscall: 'connect', Sep 01 00:12:13 stefans-speaker volumio[2993]: address: '127.0.0.1', Sep 01 00:12:13 stefans-speaker volumio[2993]: port: 9879, Sep 01 00:12:13 stefans-speaker volumio[2993]: response: undefined Sep 01 00:12:13 stefans-speaker volumio[2993]: } Sep 01 00:12:13 stefans-speaker volumio[2993]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 01 00:12:13 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Sep 01 00:12:13 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:12:13 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:12:13 stefans-speaker go-librespot[3516]: go-librespot daemon starting... Sep 01 00:12:13 stefans-speaker go-librespot[3518]: time="2026-09-01T00:12:13+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:12:13 stefans-speaker go-librespot[3518]: time="2026-09-01T00:12:13+02:00" level=debug msg="app state loaded" Sep 01 00:12:13 stefans-speaker go-librespot[3518]: time="2026-09-01T00:12:13+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:12:13 stefans-speaker go-librespot[3518]: time="2026-09-01T00:12:13+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Sep 01 00:12:13 stefans-speaker go-librespot[3518]: time="2026-09-01T00:12:13+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Sep 01 00:12:13 stefans-speaker go-librespot[3518]: time="2026-09-01T00:12:13+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Sep 01 00:12:13 stefans-speaker go-librespot[3518]: time="2026-09-01T00:12:13+02:00" level=info msg="zeroconf server listening on port 42287" Sep 01 00:12:13 stefans-speaker go-librespot[3518]: time="2026-09-01T00:12:13+02:00" level=debug msg="obtained new client token: AAHRzH43qUjjVikT9jXu7D3FEyn8ZlSsCQyJAEuUcoRBK41UFe+IcVX0W+LXK8B6rFi5mI3XyOCqHMU3TRRpqdSKEBLhBInXQXGQ14b6EgK6KA0jLPu32YhRvpiPSHk8nlPY2DIiQqKJH8jTCM1q9Il8smlbNzEwayQe1EJVlRDGcYhQf3Xs9CzN9hLP/wJ2jaenC52xjPHyTVfulDCA3ewmtFDNrOOWTj+lGzng3RUjjG73ZZhQVyV/9WM=" Sep 01 00:12:13 stefans-speaker go-librespot[3518]: time="2026-09-01T00:12:13+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 00:12:13 stefans-speaker go-librespot[3518]: time="2026-09-01T00:12:13+02:00" level=debug msg="completed keyexchange" Sep 01 00:12:13 stefans-speaker go-librespot[3518]: time="2026-09-01T00:12:13+02:00" level=debug msg="completed challenge" Sep 01 00:12:13 stefans-speaker go-librespot[3518]: time="2026-09-01T00:12:13+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:12:14 stefans-speaker sudo[3527]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:12:14 stefans-speaker sudo[3527]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-09-01 00:11' Sep 01 00:12:14 stefans-speaker sudo[3527]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:12:14 stefans-speaker go-librespot[3518]: time="2026-09-01T00:12:14+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 00:12:14 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:12:14 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:12:14 stefans-speaker sudo[3527]: pam_unix(sudo:session): session closed for user root Sep 01 00:12:14 stefans-speaker volumio[2993]: sudo: unable to resolve host stefans-speaker: System error Sep 01 00:12:14 stefans-speaker volumio-remote-updater[679]: [2026-09-01 00:12:14] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Sep 01 00:12:14 stefans-speaker volumio-remote-updater[679]: [2026-09-01 00:12:14] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Sep 01 00:12:14 stefans-speaker systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:12:14 stefans-speaker systemd[1]: volumio.service: Failed with result 'exit-code'. Sep 01 00:12:14 stefans-speaker systemd[1]: volumio.service: Consumed 36.268s CPU time. Sep 01 00:12:14 stefans-speaker systemd[1]: Started dynamicswap.service - dynamicswap service. Sep 01 00:12:14 stefans-speaker systemd[1]: dynamicswap.service: Deactivated successfully. Sep 01 00:12:14 stefans-speaker systemd[1]: volumio.service: Scheduled restart job, restart counter is at 210. Sep 01 00:12:14 stefans-speaker systemd[1]: Started dynamicswap.service - dynamicswap service. Sep 01 00:12:14 stefans-speaker systemd[1]: Stopped volumio.service - Volumio Backend Module. Sep 01 00:12:14 stefans-speaker systemd[1]: volumio.service: Consumed 36.268s CPU time. Sep 01 00:12:14 stefans-speaker systemd[1]: Started volumio.service - Volumio Backend Module. Sep 01 00:12:14 stefans-speaker systemd[1]: dynamicswap.service: Deactivated successfully. Sep 01 00:12:16 stefans-speaker volumio[3543]: info: ------------------------------------------- Sep 01 00:12:16 stefans-speaker volumio[3543]: info: ----- Volumio3 ---- Sep 01 00:12:16 stefans-speaker volumio[3543]: info: ------------------------------------------- Sep 01 00:12:16 stefans-speaker volumio[3543]: info: ----- System startup ---- Sep 01 00:12:16 stefans-speaker volumio[3543]: info: ------------------------------------------- Sep 01 00:12:17 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Sep 01 00:12:17 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:12:17 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:12:17 stefans-speaker go-librespot[3564]: go-librespot daemon starting... Sep 01 00:12:17 stefans-speaker volumio[3543]: info: MYVOLUMIO Environment detected Sep 01 00:12:17 stefans-speaker go-librespot[3567]: time="2026-09-01T00:12:17+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:12:17 stefans-speaker go-librespot[3567]: time="2026-09-01T00:12:17+02:00" level=debug msg="app state loaded" Sep 01 00:12:17 stefans-speaker go-librespot[3567]: time="2026-09-01T00:12:17+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:12:17 stefans-speaker volumio[3543]: info: Plugin folders cleanup Sep 01 00:12:17 stefans-speaker volumio[3543]: info: Scanning into folder /volumio/app/plugins/ Sep 01 00:12:17 stefans-speaker volumio[3543]: info: Scanning category audio_interface Sep 01 00:12:17 stefans-speaker volumio[3543]: info: Scanning category miscellanea Sep 01 00:12:17 stefans-speaker volumio[3543]: info: Scanning category music_service Sep 01 00:12:17 stefans-speaker volumio[3543]: info: Scanning category plugins.json Sep 01 00:12:17 stefans-speaker volumio[3543]: info: Scanning category system_controller Sep 01 00:12:17 stefans-speaker volumio[3543]: info: Scanning category user_interface Sep 01 00:12:17 stefans-speaker volumio[3543]: info: Scanning into folder /data/plugins/ Sep 01 00:12:17 stefans-speaker volumio[3543]: info: Scanning category music_service Sep 01 00:12:17 stefans-speaker volumio[3543]: info: Plugin folders cleanup completed Sep 01 00:12:17 stefans-speaker volumio[3543]: info: ------------------------------------------- Sep 01 00:12:17 stefans-speaker volumio[3543]: info: ----- Core plugins startup ---- Sep 01 00:12:17 stefans-speaker volumio[3543]: info: ------------------------------------------- Sep 01 00:12:17 stefans-speaker volumio[3543]: info: Loading plugins from folder /volumio/app/plugins/ Sep 01 00:12:17 stefans-speaker volumio[3543]: info: Adding plugin upnp to MyMusic Plugins Sep 01 00:12:17 stefans-speaker volumio[3543]: info: Adding plugin airplay_emulation to MyMusic Plugins Sep 01 00:12:17 stefans-speaker volumio[3543]: info: Adding plugin upnp_browser to MyMusic Plugins Sep 01 00:12:17 stefans-speaker volumio[3543]: info: Loading plugins from folder /data/plugins/ Sep 01 00:12:17 stefans-speaker volumio[3543]: info: Loading plugin "system"... Sep 01 00:12:17 stefans-speaker volumio[3543]: info: Loading plugin "appearance"... Sep 01 00:12:17 stefans-speaker go-librespot[3567]: time="2026-09-01T00:12:17+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Sep 01 00:12:17 stefans-speaker go-librespot[3567]: time="2026-09-01T00:12:17+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Sep 01 00:12:17 stefans-speaker go-librespot[3567]: time="2026-09-01T00:12:17+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Sep 01 00:12:17 stefans-speaker go-librespot[3567]: time="2026-09-01T00:12:17+02:00" level=info msg="zeroconf server listening on port 37437" Sep 01 00:12:17 stefans-speaker go-librespot[3567]: time="2026-09-01T00:12:17+02:00" level=debug msg="obtained new client token: AAFroodUIkEGZMg6vSJk1PkcMDrR8yc3HwVZPTOF/aS7DWC59utoLriB2vJo7gzM63aT9Zn7un7Qxq4rpyl3s4lfWpz7rZQd2xek0JGDaV3XjAFoA1dXXpizx9fzXJF9jZdCqX8TZLB4Hu9BTjQnfLznwSPw3rGKUaVkRzTkA4D828yIqEBqY1fg2YlZrHdo/4ryZ5ng1xGagzAGFCzdjWLE0yvA+u3l7arg8TG8ZySIcEtzfEE/8cKSkNU=" Sep 01 00:12:17 stefans-speaker go-librespot[3567]: time="2026-09-01T00:12:17+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 00:12:17 stefans-speaker go-librespot[3567]: time="2026-09-01T00:12:17+02:00" level=debug msg="completed keyexchange" Sep 01 00:12:17 stefans-speaker go-librespot[3567]: time="2026-09-01T00:12:17+02:00" level=debug msg="completed challenge" Sep 01 00:12:17 stefans-speaker go-librespot[3567]: time="2026-09-01T00:12:17+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:12:18 stefans-speaker go-librespot[3567]: time="2026-09-01T00:12:18+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 00:12:18 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:12:18 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:12:18 stefans-speaker volumio[3543]: info: Loading plugin "network"... Sep 01 00:12:18 stefans-speaker volumio[3543]: info: Refreshing Cached IP Addresses Sep 01 00:12:18 stefans-speaker volumio[3543]: info: Loading plugin "services"... Sep 01 00:12:18 stefans-speaker sudo[3579]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:12:18 stefans-speaker volumio[3543]: info: Loading plugin "alsa_controller"... Sep 01 00:12:18 stefans-speaker sudo[3581]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:12:18 stefans-speaker sudo[3581]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 01 00:12:18 stefans-speaker sudo[3579]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 01 00:12:18 stefans-speaker sudo[3581]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:12:18 stefans-speaker sudo[3579]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:12:18 stefans-speaker sudo[3579]: pam_unix(sudo:session): session closed for user root Sep 01 00:12:18 stefans-speaker sudo[3581]: pam_unix(sudo:session): session closed for user root Sep 01 00:12:18 stefans-speaker sudo[3588]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:12:18 stefans-speaker sudo[3588]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Sep 01 00:12:18 stefans-speaker sudo[3588]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:12:18 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 01 00:12:18 stefans-speaker volumio[3543]: info: Loading plugin "wizard"... Sep 01 00:12:18 stefans-speaker volumio[3543]: info: Loading plugin "networkfs"... Sep 01 00:12:18 stefans-speaker volumio[3543]: info: Starting Udev Watcher for removable devices Sep 01 00:12:18 stefans-speaker volumio[3543]: info: Ignoring mount for partition: boot Sep 01 00:12:18 stefans-speaker volumio[3543]: info: Ignoring mount for partition: volumio Sep 01 00:12:18 stefans-speaker volumio[3543]: info: Ignoring mount for partition: volumio_data Sep 01 00:12:18 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 01 00:12:18 stefans-speaker volumio[3543]: info: Loading plugin "volumio_command_line_client"... Sep 01 00:12:18 stefans-speaker volumio[3543]: info: Loading plugin "upnp"... Sep 01 00:12:18 stefans-speaker volumio[3543]: info: [1788214338862] Starting Upmpd Daemon Sep 01 00:12:18 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 01 00:12:18 stefans-speaker volumio[3543]: info: Loading plugin "my_music"... Sep 01 00:12:18 stefans-speaker volumio[3543]: info: Loading plugin "mpd"... Sep 01 00:12:19 stefans-speaker volumio[3543]: info: Loading plugin "upnp_browser"... Sep 01 00:12:19 stefans-speaker volumio-remote-updater[679]: [2026-09-01 00:12:19] [connect] Successful connection Sep 01 00:12:20 stefans-speaker volumio[3543]: info: Starting UPNP Browser Sep 01 00:12:20 stefans-speaker volumio[3543]: info: Loading plugin "alarm-clock"... Sep 01 00:12:20 stefans-speaker volumio[3543]: info: Loading plugin "airplay_emulation"... Sep 01 00:12:20 stefans-speaker volumio[3543]: info: Starting Shairport Sync Sep 01 00:12:20 stefans-speaker volumio[3543]: info: Loading plugin "last_100"... Sep 01 00:12:20 stefans-speaker volumio[3543]: info: Loading plugin "webradio"... Sep 01 00:12:21 stefans-speaker volumio[3543]: info: Loading plugin "i2s_dacs"... Sep 01 00:12:21 stefans-speaker volumio[3543]: info: I2S DAC not set, start Auto-detection Sep 01 00:12:21 stefans-speaker volumio[3543]: info: Loading plugin "volumiodiscovery"... Sep 01 00:12:21 stefans-speaker volumio[3543]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 01 00:12:21 stefans-speaker volumio[3543]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 01 00:12:21 stefans-speaker volumio[3543]: *** WARNING *** For more information see Sep 01 00:12:21 stefans-speaker volumio[3543]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 01 00:12:21 stefans-speaker volumio[3543]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 01 00:12:21 stefans-speaker volumio[3543]: *** WARNING *** For more information see Sep 01 00:12:21 stefans-speaker node[3543]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 01 00:12:21 stefans-speaker node[3543]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 01 00:12:21 stefans-speaker node[3543]: *** WARNING *** For more information see Sep 01 00:12:21 stefans-speaker node[3543]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 01 00:12:21 stefans-speaker node[3543]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 01 00:12:21 stefans-speaker node[3543]: *** WARNING *** For more information see Sep 01 00:12:21 stefans-speaker volumio[3543]: info: Applying required configuration parameters for plugin volumiodiscovery Sep 01 00:12:21 stefans-speaker volumio[3543]: info: Discovery: Started advertising with name: Stefan’s Speaker Sep 01 00:12:21 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 01 00:12:21 stefans-speaker volumio[3543]: info: Loading plugin "spop"... Sep 01 00:12:21 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Sep 01 00:12:21 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:12:21 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:12:21 stefans-speaker go-librespot[3615]: go-librespot daemon starting... Sep 01 00:12:21 stefans-speaker go-librespot[3616]: time="2026-09-01T00:12:21+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:12:21 stefans-speaker go-librespot[3616]: time="2026-09-01T00:12:21+02:00" level=debug msg="app state loaded" Sep 01 00:12:21 stefans-speaker go-librespot[3616]: time="2026-09-01T00:12:21+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:12:21 stefans-speaker go-librespot[3616]: time="2026-09-01T00:12:21+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 00:12:21 stefans-speaker go-librespot[3616]: time="2026-09-01T00:12:21+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 01 00:12:21 stefans-speaker go-librespot[3616]: time="2026-09-01T00:12:21+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 01 00:12:21 stefans-speaker go-librespot[3616]: time="2026-09-01T00:12:21+02:00" level=info msg="zeroconf server listening on port 39369" Sep 01 00:12:22 stefans-speaker sudo[3588]: pam_unix(sudo:session): session closed for user root Sep 01 00:12:22 stefans-speaker go-librespot[3616]: time="2026-09-01T00:12:22+02:00" level=debug msg="obtained new client token: AAEyIadaNuHE/bIZUwCWoI9b0U2AoOW/WZHZlDE8FVVfcVzPm2VerO88XTTKTG4QsRmOSEEBdgPEamcIVkfJq1Bbc/IA1jlOq1yBt3XtNjnuRwlWT6GvMHiMgoMPjw8iH5udllbp2TF6paDYlLQJZ6dSLGDHH322z/EEt07MgwvqnXJ7Xn0HFB6uuO8VDqiVqqFCsOz0vMaxaK+dl2iMPuK1bR62qutxq4f3O/BrxG/+ofp9y0LF6m4V" Sep 01 00:12:22 stefans-speaker go-librespot[3616]: time="2026-09-01T00:12:22+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 00:12:22 stefans-speaker go-librespot[3616]: time="2026-09-01T00:12:22+02:00" level=debug msg="completed keyexchange" Sep 01 00:12:22 stefans-speaker go-librespot[3616]: time="2026-09-01T00:12:22+02:00" level=debug msg="completed challenge" Sep 01 00:12:22 stefans-speaker go-librespot[3616]: time="2026-09-01T00:12:22+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:12:22 stefans-speaker volumio[3543]: info: Loading plugin "ytcr"... Sep 01 00:12:22 stefans-speaker go-librespot[3616]: time="2026-09-01T00:12:22+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 00:12:22 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:12:22 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:12:23 stefans-speaker volumio[3543]: info: Loading plugin "outputs"... Sep 01 00:12:23 stefans-speaker volumio[3543]: info: Loading plugin "albumart"... Sep 01 00:12:23 stefans-speaker volumio[3543]: info: Plugin example_plugin is not enabled Sep 01 00:12:23 stefans-speaker volumio[3543]: info: Loading plugin "inputs"... Sep 01 00:12:23 stefans-speaker volumio[3543]: info: Loading plugin "updater_comm"... Sep 01 00:12:23 stefans-speaker volumio[3543]: info: Plugin mpdemulation is not enabled Sep 01 00:12:23 stefans-speaker volumio[3543]: info: Loading plugin "rest_api"... Sep 01 00:12:23 stefans-speaker volumio[3543]: info: Loading plugin "websocket"... Sep 01 00:12:23 stefans-speaker volumio[3543]: info: Starting Socket.io Server version 1.7.4 Sep 01 00:12:23 stefans-speaker volumio[3543]: info: Loading i18n strings for locale nl Sep 01 00:12:23 stefans-speaker volumio[3543]: Updating browse sources language Sep 01 00:12:23 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 00:12:24 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 00:12:24 stefans-speaker volumio[3543]: info: CoreCommandRouter::initPlayerControls Sep 01 00:12:24 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:12:24 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:12:24 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:12:24 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:12:24 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:12:24 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:12:24 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:12:24 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:12:24 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 00:12:24 stefans-speaker volumio[3543]: Express server listening on port 3000 Sep 01 00:12:24 stefans-speaker volumio[3543]: [Metrics] WebUI: 8s 90.59ms Sep 01 00:12:24 stefans-speaker volumio[3543]: info: CoreStateMachine::resetVolumioState Sep 01 00:12:24 stefans-speaker volumio[3543]: info: CoreStateMachine::getcurrentVolume Sep 01 00:12:24 stefans-speaker volumio[3543]: info: CoreCommandRouter::volumioRetrievevolume Sep 01 00:12:24 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:12:24 stefans-speaker volumio[3543]: info: Cannot read play queue from file Sep 01 00:12:24 stefans-speaker volumio[3543]: info: Volumio Network Manager: Network status updated: 2 Sep 01 00:12:24 stefans-speaker volumio[3624]: Forking 3 albumart workers Sep 01 00:12:24 stefans-speaker volumio[3543]: info: VolumeController:: Volume=70 Mute =false Sep 01 00:12:24 stefans-speaker volumio[3543]: info: CoreStateMachine::pushState Sep 01 00:12:24 stefans-speaker volumio[3543]: info: CorePlayQueue::getTrack 0 Sep 01 00:12:24 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 01 00:12:24 stefans-speaker volumio[3543]: info: CoreCommandRouter::volumioPushState Sep 01 00:12:24 stefans-speaker volumio[3543]: info: CoreStateMachine::updateTrackBlock Sep 01 00:12:24 stefans-speaker volumio[3543]: info: CorePlayQueue::getTrackBlock Sep 01 00:12:24 stefans-speaker volumio[3543]: info: CoreCommandRouter::volumioRetrievevolume Sep 01 00:12:24 stefans-speaker volumio[3543]: info: CoreStateMachine::setRepeat null single undefined Sep 01 00:12:24 stefans-speaker volumio[3543]: info: CoreStateMachine::pushState Sep 01 00:12:24 stefans-speaker volumio[3543]: info: CorePlayQueue::getTrack 0 Sep 01 00:12:24 stefans-speaker volumio[3543]: info: CoreCommandRouter::volumioPushState Sep 01 00:12:24 stefans-speaker volumio[3543]: info: CoreStateMachine::setRandom null Sep 01 00:12:24 stefans-speaker volumio[3543]: info: CoreStateMachine::pushState Sep 01 00:12:24 stefans-speaker volumio[3543]: info: CorePlayQueue::getTrack 0 Sep 01 00:12:24 stefans-speaker volumio[3543]: info: CoreCommandRouter::volumioPushState Sep 01 00:12:24 stefans-speaker volumio[3543]: info: Setting Device type: Raspberry PI Sep 01 00:12:24 stefans-speaker volumio[3543]: info: VolumeController:: Volume=70 Mute =false Sep 01 00:12:24 stefans-speaker volumio[3543]: info: CoreStateMachine::pushState Sep 01 00:12:24 stefans-speaker volumio[3543]: info: CorePlayQueue::getTrack 0 Sep 01 00:12:24 stefans-speaker volumio[3543]: info: CoreCommandRouter::volumioPushState Sep 01 00:12:24 stefans-speaker volumio[3543]: info: Completed loading Core Plugins Sep 01 00:12:24 stefans-speaker volumio[3543]: info: Preparing to generate the ALSA configuration file Sep 01 00:12:24 stefans-speaker volumio[3543]: info: Discovery: adding a312d0fa-c0eb-45ad-a25b-79fcdf237e8a Sep 01 00:12:24 stefans-speaker volumio[3543]: info: Discovery: Found device Stefan’s Speaker Sep 01 00:12:24 stefans-speaker volumio[3543]: info: CoreCommandRouter::volumioGetState Sep 01 00:12:24 stefans-speaker volumio[3543]: info: CorePlayQueue::getTrack 0 Sep 01 00:12:24 stefans-speaker volumio[3543]: info: Discovery: this is already registered, a312d0fa-c0eb-45ad-a25b-79fcdf237e8a Sep 01 00:12:24 stefans-speaker volumio[3543]: info: Discovery: Found device Stefan’s Speaker Sep 01 00:12:24 stefans-speaker volumio[3543]: info: CoreCommandRouter::volumioGetState Sep 01 00:12:24 stefans-speaker volumio[3543]: info: CorePlayQueue::getTrack 0 Sep 01 00:12:24 stefans-speaker volumio[3543]: info: Asound.conf file unchanged, so no further update is needed Sep 01 00:12:24 stefans-speaker volumio[3543]: info: Output device has changed, restarting MPD Sep 01 00:12:24 stefans-speaker volumio[3543]: info: Output device has changed, restarting Shairport Sync Sep 01 00:12:24 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:12:24 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:12:24 stefans-speaker sudo[3679]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:12:24 stefans-speaker sudo[3679]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 01 00:12:24 stefans-speaker sudo[3679]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:12:24 stefans-speaker sudo[3679]: pam_unix(sudo:session): session closed for user root Sep 01 00:12:24 stefans-speaker sudo[3681]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:12:24 stefans-speaker sudo[3681]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 01 00:12:24 stefans-speaker sudo[3681]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:12:24 stefans-speaker volumio[3543]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 01 00:12:24 stefans-speaker volumio[3543]: info: ___________ START PLUGINS ___________ Sep 01 00:12:25 stefans-speaker volumio[3543]: info: ControllerMpd::onStart: Initializing MPD Sep 01 00:12:25 stefans-speaker volumio[3543]: info: Creating MPD Configuration file Sep 01 00:12:25 stefans-speaker systemd[1]: Stopping mpd.service - Music Player Daemon... Sep 01 00:12:25 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 00:12:25 stefans-speaker volumio[3543]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 01 00:12:25 stefans-speaker volumio[3543]: info: [1788214345095] CoreMusicLibrary::Adding element Media Servers Sep 01 00:12:25 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 00:12:25 stefans-speaker volumio[3543]: info: UPNP Browser: Client initialized successfully Sep 01 00:12:25 stefans-speaker systemd[1]: mpd.service: Deactivated successfully. Sep 01 00:12:25 stefans-speaker sudo[3690]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:12:25 stefans-speaker systemd[1]: Stopped mpd.service - Music Player Daemon. Sep 01 00:12:25 stefans-speaker systemd[1]: mpd.service: Consumed 4.499s CPU time. Sep 01 00:12:25 stefans-speaker systemd[1]: mpd.socket: Deactivated successfully. Sep 01 00:12:25 stefans-speaker systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Sep 01 00:12:25 stefans-speaker systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Sep 01 00:12:25 stefans-speaker sudo[3692]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:12:25 stefans-speaker sudo[3690]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 01 00:12:25 stefans-speaker sudo[3692]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 01 00:12:25 stefans-speaker sudo[3690]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:12:25 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:12:25 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:12:25 stefans-speaker sudo[3692]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:12:25 stefans-speaker sudo[3690]: pam_unix(sudo:session): session closed for user root Sep 01 00:12:25 stefans-speaker systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Sep 01 00:12:25 stefans-speaker systemd[1]: Starting mpd.service - Music Player Daemon... Sep 01 00:12:25 stefans-speaker volumio[3543]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 01 00:12:25 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:12:25 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:12:25 stefans-speaker systemd[1]: mpd.service: Deactivated successfully. Sep 01 00:12:25 stefans-speaker systemd[1]: Stopped mpd.service - Music Player Daemon. Sep 01 00:12:25 stefans-speaker systemd[1]: mpd.socket: Deactivated successfully. Sep 01 00:12:25 stefans-speaker systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Sep 01 00:12:25 stefans-speaker systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Sep 01 00:12:25 stefans-speaker systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Sep 01 00:12:25 stefans-speaker systemd[1]: Starting mpd.service - Music Player Daemon... Sep 01 00:12:25 stefans-speaker volumio[3543]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 01 00:12:25 stefans-speaker volumio[3543]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 01 00:12:25 stefans-speaker volumio[3543]: info: [1788214345348] CoreMusicLibrary::Adding element Last_100 Sep 01 00:12:25 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 00:12:25 stefans-speaker volumio[3543]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 01 00:12:25 stefans-speaker volumio[3543]: info: [1788214345356] CoreMusicLibrary::Adding element Webradio Sep 01 00:12:25 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 00:12:25 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 01 00:12:25 stefans-speaker volumio[3543]: info: Initializing BBC Radios Sep 01 00:12:25 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 01 00:12:25 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:12:25 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Sep 01 00:12:25 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:12:25 stefans-speaker volumio[3543]: info: Creating Spotify config file Sep 01 00:12:25 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:12:25 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:12:25 stefans-speaker go-librespot[3720]: go-librespot daemon starting... Sep 01 00:12:25 stefans-speaker sudo[3706]: root : unable to resolve host stefans-speaker: System error Sep 01 00:12:25 stefans-speaker sudo[3706]: sudo: unable to resolve host stefans-speaker: System error Sep 01 00:12:25 stefans-speaker sudo[3706]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Sep 01 00:12:25 stefans-speaker sudo[3706]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Sep 01 00:12:25 stefans-speaker go-librespot[3721]: time="2026-09-01T00:12:25+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:12:25 stefans-speaker sudo[3706]: pam_unix(sudo:session): session closed for user root Sep 01 00:12:26 stefans-speaker go-librespot[3721]: time="2026-09-01T00:12:26+02:00" level=info msg="zeroconf server listening on port 46065" Sep 01 00:12:26 stefans-speaker volumio[3641]: Starting albumart workers Sep 01 00:12:26 stefans-speaker volumio[3543]: info: Volumio Calling Home Sep 01 00:12:26 stefans-speaker volumio[3543]: info: MPD Permissions set Sep 01 00:12:26 stefans-speaker volumio[3543]: info: MPD Permissions set Sep 01 00:12:26 stefans-speaker volumio[3543]: info: Spotify config file written Sep 01 00:12:26 stefans-speaker sudo[3735]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:12:26 stefans-speaker volumio[3642]: Starting albumart workers Sep 01 00:12:26 stefans-speaker sudo[3735]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Sep 01 00:12:26 stefans-speaker sudo[3735]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:12:26 stefans-speaker volumio[3640]: Starting albumart workers Sep 01 00:12:26 stefans-speaker systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Sep 01 00:12:26 stefans-speaker systemd[1]: go-librespot-daemon.service: Deactivated successfully. Sep 01 00:12:26 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:12:26 stefans-speaker volumio[3543]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Sep 01 00:12:26 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:12:26 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:12:26 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:12:26 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:12:26 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:12:26 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:12:26 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:12:26 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:12:26 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:12:26 stefans-speaker go-librespot[3737]: go-librespot daemon starting... Sep 01 00:12:26 stefans-speaker sudo[3735]: pam_unix(sudo:session): session closed for user root Sep 01 00:12:27 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:12:27 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:12:27 stefans-speaker go-librespot[3740]: time="2026-09-01T00:12:27+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:12:27 stefans-speaker go-librespot[3740]: time="2026-09-01T00:12:27+02:00" level=debug msg="app state loaded" Sep 01 00:12:27 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:12:27 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:12:27 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:12:27 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:12:27 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:12:27 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:12:27 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:12:27 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:12:27 stefans-speaker go-librespot[3740]: time="2026-09-01T00:12:27+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:12:27 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:12:27 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:12:27 stefans-speaker volumio[3543]: info: No need to fix Spotify hosts Sep 01 00:12:27 stefans-speaker go-librespot[3740]: time="2026-09-01T00:12:27+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Sep 01 00:12:27 stefans-speaker go-librespot[3740]: time="2026-09-01T00:12:27+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Sep 01 00:12:27 stefans-speaker go-librespot[3740]: time="2026-09-01T00:12:27+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Sep 01 00:12:27 stefans-speaker go-librespot[3740]: time="2026-09-01T00:12:27+02:00" level=info msg="zeroconf server listening on port 40257" Sep 01 00:12:27 stefans-speaker volumio[3543]: info: Volumio called home Sep 01 00:12:27 stefans-speaker go-librespot[3740]: time="2026-09-01T00:12:27+02:00" level=debug msg="obtained new client token: AAG9gyYl4G8vFBz/u82oWJSc88PKPCGp82eP+YNLMiykWBgq+X6BbJt7I6zibjSxtxruoZkMWz27ntgIAjXy6GaNE5ejNwoOjNmx/w4ZgP6rmyl46hkP0t62CpGu+WQz13wyBo3beXyVWfZ5Kv8PNgrrNUgJDpxRh/rdSTCr80HHlg0Sv+HizbfKkwVK25mOzMy5a1ItTVfGFxjkwXZ5dJ8e55O+cLeLSWHhji5l0Lh72xhCy60v6YRktVQ=" Sep 01 00:12:27 stefans-speaker go-librespot[3740]: time="2026-09-01T00:12:27+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 00:12:27 stefans-speaker go-librespot[3740]: time="2026-09-01T00:12:27+02:00" level=debug msg="completed keyexchange" Sep 01 00:12:27 stefans-speaker go-librespot[3740]: time="2026-09-01T00:12:27+02:00" level=debug msg="completed challenge" Sep 01 00:12:27 stefans-speaker go-librespot[3740]: time="2026-09-01T00:12:27+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:12:27 stefans-speaker go-librespot[3740]: time="2026-09-01T00:12:27+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 00:12:27 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:12:27 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:12:28 stefans-speaker volumio[3543]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Sep 01 00:12:28 stefans-speaker volumio[3543]: SPOTIFY: BQD1_cedFQnpVMXAEBrSyxJERYbP2rL-ow2WBPEqOfU69QowHb08yPsqpEbVSGZ9NjJ7bXCm9guklMTeCCWTGne1pBr-oiGOB_87aHO2AOqSusZiE3CNfUTlVKwrUs6xjwx1hCKoDZR3aqtPM3PIS5wYvxjBJfadaXOGpAwHRH7TGelfK68ZHT9N8u7U1yRdbjNuDISeYbs5eCxmPpg2atd22MRaRW09J4A3ZpyAZuhLDEe3_iAI6BCdLqb6sseVfxlvS_LHKNcCIxZIvkrL-O73iGBgloBzGTRxLoCZkkgKgUvd6C2X1HZg7Jw_ZOs Sep 01 00:12:28 stefans-speaker volumio[3543]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Sep 01 00:12:28 stefans-speaker volumio[3543]: info: New Spotify access token = BQD1_cedFQnpVMXAEBrSyxJERYbP2rL-ow2WBPEqOfU69QowHb08yPsqpEbVSGZ9NjJ7bXCm9guklMTeCCWTGne1pBr-oiGOB_87aHO2AOqSusZiE3CNfUTlVKwrUs6xjwx1hCKoDZR3aqtPM3PIS5wYvxjBJfadaXOGpAwHRH7TGelfK68ZHT9N8u7U1yRdbjNuDISeYbs5eCxmPpg2atd22MRaRW09J4A3ZpyAZuhLDEe3_iAI6BCdLqb6sseVfxlvS_LHKNcCIxZIvkrL-O73iGBgloBzGTRxLoCZkkgKgUvd6C2X1HZg7Jw_ZOs Sep 01 00:12:28 stefans-speaker volumio[3543]: info: Spotify credentials grant success - running version from March 24, 2019 Sep 01 00:12:28 stefans-speaker volumio[3543]: info: Starting Shairport Sync Sep 01 00:12:28 stefans-speaker volumio[3543]: info: Starting Shairport Sync Sep 01 00:12:28 stefans-speaker volumio[3543]: info: Starting Shairport Sync Sep 01 00:12:28 stefans-speaker sudo[3775]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:12:28 stefans-speaker sudo[3775]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 01 00:12:28 stefans-speaker sudo[3775]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:12:28 stefans-speaker sudo[3777]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:12:28 stefans-speaker sudo[3779]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:12:28 stefans-speaker sudo[3777]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 01 00:12:28 stefans-speaker sudo[3777]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:12:28 stefans-speaker sudo[3779]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 01 00:12:28 stefans-speaker sudo[3779]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:12:28 stefans-speaker systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Sep 01 00:12:28 stefans-speaker systemd[1]: shairport-sync.service: Deactivated successfully. Sep 01 00:12:28 stefans-speaker systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Sep 01 00:12:28 stefans-speaker systemd[1]: shairport-sync.service: Consumed 1.951s CPU time. Sep 01 00:12:28 stefans-speaker volumio[3543]: info: CoreCommandRouter::volumioGetState Sep 01 00:12:28 stefans-speaker volumio[3543]: info: CorePlayQueue::getTrack 0 Sep 01 00:12:28 stefans-speaker systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Sep 01 00:12:28 stefans-speaker sudo[3775]: pam_unix(sudo:session): session closed for user root Sep 01 00:12:28 stefans-speaker sudo[3777]: pam_unix(sudo:session): session closed for user root Sep 01 00:12:28 stefans-speaker sudo[3779]: pam_unix(sudo:session): session closed for user root Sep 01 00:12:28 stefans-speaker volumio[3543]: info: Shairport-Sync Started Sep 01 00:12:28 stefans-speaker volumio[3543]: Error adding Membership: Error: addMembership EINVAL Sep 01 00:12:28 stefans-speaker volumio[3543]: info: Shairport-Sync Started Sep 01 00:12:28 stefans-speaker volumio[3543]: info: Shairport-Sync Started Sep 01 00:12:28 stefans-speaker volumio[3543]: SPOTIFY: User informations: {"account_id":"zltuAJDW9c","country":"RO","display_name":"emanueluss","email":"emanuel.grecescu@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31mmtxvuufe76qdkk6caepwk3fcy"},"followers":{"href":null,"total":3},"href":"https://api.spotify.com/v1/users/31mmtxvuufe76qdkk6caepwk3fcy","id":"31mmtxvuufe76qdkk6caepwk3fcy","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee852e7ddfcb02af85c1462f3412","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b822e7ddfcb02af85c1462f3412","width":64}],"product":"premium","type":"user","uri":"spotify:user:31mmtxvuufe76qdkk6caepwk3fcy"} Sep 01 00:12:28 stefans-speaker volumio[3543]: info: Spotify Successfully logged in Sep 01 00:12:28 stefans-speaker volumio[3543]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 01 00:12:28 stefans-speaker volumio[3543]: info: [1788214348650] CoreMusicLibrary::Adding element Spotify Sep 01 00:12:28 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 00:12:28 stefans-speaker volumio[3543]: Cannot find translation for source Spotify Sep 01 00:12:28 stefans-speaker sudo[3813]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:12:28 stefans-speaker sudo[3813]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 01 00:12:28 stefans-speaker sudo[3813]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:12:28 stefans-speaker sudo[3813]: pam_unix(sudo:session): session closed for user root Sep 01 00:12:29 stefans-speaker sudo[3815]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:12:29 stefans-speaker sudo[3815]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 01 00:12:29 stefans-speaker sudo[3815]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:12:29 stefans-speaker sudo[3815]: pam_unix(sudo:session): session closed for user root Sep 01 00:12:29 stefans-speaker sudo[3819]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:12:29 stefans-speaker sudo[3819]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Sep 01 00:12:29 stefans-speaker sudo[3819]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:12:29 stefans-speaker volumio[3543]: info: [yt-cast-receiver] DIAL server listening on port 8098 Sep 01 00:12:29 stefans-speaker volumio[3543]: info: CoreCommandRouter::volumioRetrievevolume Sep 01 00:12:29 stefans-speaker sudo[3819]: pam_unix(sudo:session): session closed for user root Sep 01 00:12:29 stefans-speaker volumio[3543]: info: Upmpdcli Daemon Started Sep 01 00:12:29 stefans-speaker volumio[3543]: info: VolumeController:: Volume=70 Mute =false Sep 01 00:12:29 stefans-speaker volumio[3543]: info: CoreCommandRouter::volumioGetState Sep 01 00:12:29 stefans-speaker volumio[3543]: info: CorePlayQueue::getTrack 0 Sep 01 00:12:29 stefans-speaker volumio[3543]: info: CoreStateMachine::pushState Sep 01 00:12:29 stefans-speaker volumio[3543]: info: CorePlayQueue::getTrack 0 Sep 01 00:12:29 stefans-speaker volumio[3543]: info: CoreCommandRouter::volumioPushState Sep 01 00:12:30 stefans-speaker mpd[3728]: 2026-09-01T00:12:30 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Sep 01 00:12:30 stefans-speaker systemd[1]: Started mpd.service - Music Player Daemon. Sep 01 00:12:30 stefans-speaker sudo[3692]: pam_unix(sudo:session): session closed for user root Sep 01 00:12:30 stefans-speaker sudo[3681]: pam_unix(sudo:session): session closed for user root Sep 01 00:12:30 stefans-speaker volumio[3543]: error: MPD error: The expression evaluated to a falsy value: Sep 01 00:12:30 stefans-speaker volumio[3543]: assert.ok(self.idling) Sep 01 00:12:30 stefans-speaker volumio[3543]: error: The expression evaluated to a falsy value: Sep 01 00:12:30 stefans-speaker volumio[3543]: assert.ok(self.idling) Sep 01 00:12:30 stefans-speaker volumio[3543]: error: updateQueue error: null Sep 01 00:12:30 stefans-speaker volumio[3543]: info: MPD running with PID3728 Sep 01 00:12:30 stefans-speaker volumio[3543]: ,establishing connection Sep 01 00:12:30 stefans-speaker volumio[3543]: info: Completed starting Core Plugins Sep 01 00:12:30 stefans-speaker volumio[3543]: info: ------------------------------------------- Sep 01 00:12:30 stefans-speaker volumio[3543]: info: ----- MyVolumio plugins startup ---- Sep 01 00:12:30 stefans-speaker volumio[3543]: info: ------------------------------------------- Sep 01 00:12:30 stefans-speaker volumio[3543]: info: [MyVolumio PluginManager] Fetching plans data.... Sep 01 00:12:30 stefans-speaker volumio[3543]: error: updateQueue error: null Sep 01 00:12:30 stefans-speaker volumio[3543]: info: go-librespot daemon successfully initialized Sep 01 00:12:31 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Sep 01 00:12:31 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:12:31 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:12:31 stefans-speaker go-librespot[3829]: go-librespot daemon starting... Sep 01 00:12:31 stefans-speaker go-librespot[3830]: time="2026-09-01T00:12:31+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:12:31 stefans-speaker go-librespot[3830]: time="2026-09-01T00:12:31+02:00" level=debug msg="app state loaded" Sep 01 00:12:31 stefans-speaker go-librespot[3830]: time="2026-09-01T00:12:31+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:12:31 stefans-speaker go-librespot[3830]: time="2026-09-01T00:12:31+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 00:12:31 stefans-speaker go-librespot[3830]: time="2026-09-01T00:12:31+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 01 00:12:31 stefans-speaker go-librespot[3830]: time="2026-09-01T00:12:31+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 01 00:12:31 stefans-speaker go-librespot[3830]: time="2026-09-01T00:12:31+02:00" level=info msg="zeroconf server listening on port 35357" Sep 01 00:12:31 stefans-speaker go-librespot[3830]: time="2026-09-01T00:12:31+02:00" level=debug msg="obtained new client token: AAGQn24Fh7p9N2P3AQ06lCFrY8bBXjRtlXdam9VYF7lPHhJzwNpwA4rnoWjMebS0wjltx0Z27427q01c3xH8QPzDHI8uM93z4NZukF/xrLQXGaq9mSXswPKrb/pLkwinPw29prgTEeYRwodYBUyWyGP0OMEjwxTyuuPNJKf9QTLDELe+tJqb3EYbwxONdL7VOrS7OQdgEiNdNSui/WsFkO8unIo+pElZMG/IeCtnmCgF/CiRaGTbDUKrksM=" Sep 01 00:12:31 stefans-speaker go-librespot[3830]: time="2026-09-01T00:12:31+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 00:12:31 stefans-speaker go-librespot[3830]: time="2026-09-01T00:12:31+02:00" level=debug msg="completed keyexchange" Sep 01 00:12:31 stefans-speaker go-librespot[3830]: time="2026-09-01T00:12:31+02:00" level=debug msg="completed challenge" Sep 01 00:12:31 stefans-speaker go-librespot[3830]: time="2026-09-01T00:12:31+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:12:31 stefans-speaker go-librespot[3830]: time="2026-09-01T00:12:31+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 00:12:31 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:12:31 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:12:31 stefans-speaker volumio-remote-updater[679]: [2026-09-01 00:12:31] [connect] Successful connection Sep 01 00:12:31 stefans-speaker volumio-remote-updater[679]: [2026-09-01 00:12:31] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1788214351 101 Sep 01 00:12:31 stefans-speaker volumio[3543]: 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: 2 Sep 01 00:12:33 stefans-speaker sudo[3844]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:12:33 stefans-speaker sudo[3846]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:12:33 stefans-speaker sudo[3844]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Sep 01 00:12:33 stefans-speaker sudo[3844]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:12:33 stefans-speaker sudo[3846]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Sep 01 00:12:33 stefans-speaker sudo[3846]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:12:33 stefans-speaker systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Sep 01 00:12:33 stefans-speaker systemd[1]: mpd_monitor.service: Deactivated successfully. Sep 01 00:12:33 stefans-speaker systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Sep 01 00:12:33 stefans-speaker systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Sep 01 00:12:33 stefans-speaker sudo[3844]: pam_unix(sudo:session): session closed for user root Sep 01 00:12:33 stefans-speaker mpd_monitor.sh[3849]: MPD Monitor Service: Starting MPD Monitor Service Sep 01 00:12:33 stefans-speaker sudo[3846]: pam_unix(sudo:session): session closed for user root Sep 01 00:12:33 stefans-speaker volumio[3543]: info: Successfully started MPD Monitor Sep 01 00:12:33 stefans-speaker volumio[3543]: info: Successfully started MPD Monitor Sep 01 00:12:33 stefans-speaker volumio[3543]: info: Initializing connection to go-librespot Websocket Sep 01 00:12:33 stefans-speaker volumio[3543]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 00:12:34 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Sep 01 00:12:34 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:12:34 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:12:34 stefans-speaker go-librespot[3853]: go-librespot daemon starting... Sep 01 00:12:34 stefans-speaker go-librespot[3854]: time="2026-09-01T00:12:34+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:12:34 stefans-speaker go-librespot[3854]: time="2026-09-01T00:12:34+02:00" level=debug msg="app state loaded" Sep 01 00:12:34 stefans-speaker go-librespot[3854]: time="2026-09-01T00:12:34+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:12:35 stefans-speaker go-librespot[3854]: time="2026-09-01T00:12:35+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Sep 01 00:12:35 stefans-speaker go-librespot[3854]: time="2026-09-01T00:12:35+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Sep 01 00:12:35 stefans-speaker go-librespot[3854]: time="2026-09-01T00:12:35+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Sep 01 00:12:35 stefans-speaker go-librespot[3854]: time="2026-09-01T00:12:35+02:00" level=info msg="zeroconf server listening on port 42869" Sep 01 00:12:35 stefans-speaker go-librespot[3854]: time="2026-09-01T00:12:35+02:00" level=debug msg="obtained new client token: AAFUJMnyuiQW4qutz3SbcPtfX8yl7dhmHlDkVj/Pyf/jxB3T65sRUDN9imyc4ppgY0vOphzBRxTdgXzdsxanZQ2/v87S66uzJ/kwQTpAu1e2M86EZ01TtPorDewdBO8J7+76GzGOC5SOibLYK8kvQlKf5nSx+Psq9NbkcUVe77lSScmIVHp3HfTjbMmGIDxGx5aATg1jM6pPU2WB+yMpqxMl/hCkEn5lz/LFLKo8A5447gHGQlYVgwXN" Sep 01 00:12:35 stefans-speaker volumio[3543]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Sep 01 00:12:35 stefans-speaker go-librespot[3854]: time="2026-09-01T00:12:35+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 00:12:35 stefans-speaker go-librespot[3854]: time="2026-09-01T00:12:35+02:00" level=debug msg="completed keyexchange" Sep 01 00:12:35 stefans-speaker go-librespot[3854]: time="2026-09-01T00:12:35+02:00" level=debug msg="completed challenge" Sep 01 00:12:35 stefans-speaker go-librespot[3854]: time="2026-09-01T00:12:35+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:12:35 stefans-speaker go-librespot[3854]: time="2026-09-01T00:12:35+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 00:12:35 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:12:35 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:12:36 stefans-speaker volumio[3543]: info: Initializing connection to go-librespot Websocket Sep 01 00:12:36 stefans-speaker volumio[3543]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 00:12:38 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Sep 01 00:12:38 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:12:38 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:12:38 stefans-speaker go-librespot[3863]: go-librespot daemon starting... Sep 01 00:12:38 stefans-speaker go-librespot[3864]: time="2026-09-01T00:12:38+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:12:38 stefans-speaker go-librespot[3864]: time="2026-09-01T00:12:38+02:00" level=debug msg="app state loaded" Sep 01 00:12:38 stefans-speaker go-librespot[3864]: time="2026-09-01T00:12:38+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:12:38 stefans-speaker volumio[3543]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Sep 01 00:12:38 stefans-speaker volumio[3543]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Sep 01 00:12:38 stefans-speaker volumio[3543]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Sep 01 00:12:38 stefans-speaker volumio[3543]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Sep 01 00:12:38 stefans-speaker volumio[3543]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Sep 01 00:12:38 stefans-speaker volumio[3543]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Sep 01 00:12:38 stefans-speaker volumio[3543]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Sep 01 00:12:38 stefans-speaker volumio[3543]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Sep 01 00:12:38 stefans-speaker volumio[3543]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Sep 01 00:12:38 stefans-speaker volumio[3543]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Sep 01 00:12:38 stefans-speaker volumio[3543]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Sep 01 00:12:38 stefans-speaker volumio[3543]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Sep 01 00:12:38 stefans-speaker volumio[3543]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Sep 01 00:12:38 stefans-speaker volumio[3543]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Sep 01 00:12:38 stefans-speaker volumio[3543]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Sep 01 00:12:38 stefans-speaker volumio[3543]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Sep 01 00:12:38 stefans-speaker volumio[3543]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Sep 01 00:12:38 stefans-speaker volumio[3543]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Sep 01 00:12:38 stefans-speaker volumio[3543]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Sep 01 00:12:38 stefans-speaker volumio[3543]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Sep 01 00:12:38 stefans-speaker volumio[3543]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Sep 01 00:12:38 stefans-speaker volumio[3543]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Sep 01 00:12:38 stefans-speaker volumio[3543]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Sep 01 00:12:38 stefans-speaker volumio[3543]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Sep 01 00:12:38 stefans-speaker volumio[3543]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Sep 01 00:12:38 stefans-speaker volumio[3543]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Sep 01 00:12:38 stefans-speaker volumio[3543]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Sep 01 00:12:38 stefans-speaker volumio[3543]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Sep 01 00:12:38 stefans-speaker go-librespot[3864]: time="2026-09-01T00:12:38+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 00:12:38 stefans-speaker go-librespot[3864]: time="2026-09-01T00:12:38+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 01 00:12:38 stefans-speaker go-librespot[3864]: time="2026-09-01T00:12:38+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 01 00:12:38 stefans-speaker volumio[3543]: info: Adding plugin bluetooth to MyMusic Plugins Sep 01 00:12:38 stefans-speaker volumio[3543]: info: Adding plugin multiroom to MyMusic Plugins Sep 01 00:12:38 stefans-speaker volumio[3543]: info: Adding plugin metavolumio to MyMusic Plugins Sep 01 00:12:38 stefans-speaker volumio[3543]: info: Adding plugin cd_controller to MyMusic Plugins Sep 01 00:12:38 stefans-speaker volumio[3543]: info: Adding plugin qobuzconnect to MyMusic Plugins Sep 01 00:12:38 stefans-speaker volumio[3543]: info: Adding plugin smart_inputs to MyMusic Plugins Sep 01 00:12:38 stefans-speaker volumio[3543]: info: Adding plugin tidalconnect to MyMusic Plugins Sep 01 00:12:38 stefans-speaker volumio[3543]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Sep 01 00:12:38 stefans-speaker go-librespot[3864]: time="2026-09-01T00:12:38+02:00" level=info msg="zeroconf server listening on port 44325" Sep 01 00:12:38 stefans-speaker go-librespot[3864]: time="2026-09-01T00:12:38+02:00" level=debug msg="obtained new client token: AAGD4iLhlDtUYhUGYD9GVK0M6bRlFfyrq+oMwF+n39fZIw9dmHodnS8R+FCZjeItWG+CqAd2KtZWHe73S3Mw/sas1vMD43e+w0HNNniGDJqDG8sdzgu0WOOHy2ramkvSWuPtifqFd9/VojB75Aqlqms0n+yyo/WjXKHdwerLjkNJ0aghVZZCgYuZ769JgxkNSfdn2LEuF95V8UCzYg6ktprWnF1jq4TRX/sdtdmx0ga7OuL9sQ/hjnOR/24=" Sep 01 00:12:39 stefans-speaker go-librespot[3864]: time="2026-09-01T00:12:39+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 00:12:39 stefans-speaker go-librespot[3864]: time="2026-09-01T00:12:39+02:00" level=debug msg="completed keyexchange" Sep 01 00:12:39 stefans-speaker go-librespot[3864]: time="2026-09-01T00:12:39+02:00" level=debug msg="completed challenge" Sep 01 00:12:39 stefans-speaker go-librespot[3864]: time="2026-09-01T00:12:39+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:12:39 stefans-speaker go-librespot[3864]: time="2026-09-01T00:12:39+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 00:12:39 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:12:39 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:12:39 stefans-speaker volumio[3543]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Sep 01 00:12:39 stefans-speaker volumio[3543]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Sep 01 00:12:39 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:12:39 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:12:39 stefans-speaker volumio[3543]: info: Starting MyVolumio Remote Streaming Endpoints Sep 01 00:12:39 stefans-speaker volumio[3543]: info: MyVolumio login type: Token Sep 01 00:12:39 stefans-speaker volumio[3543]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Sep 01 00:12:39 stefans-speaker volumio[3543]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Sep 01 00:12:40 stefans-speaker volumio[3543]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Sep 01 00:12:40 stefans-speaker volumio[3543]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Sep 01 00:12:40 stefans-speaker volumio[3543]: info: Streaming services startup Sep 01 00:12:40 stefans-speaker volumio[3543]: info: Starting Streaming Daemon Sep 01 00:12:40 stefans-speaker volumio[3543]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Sep 01 00:12:40 stefans-speaker sudo[3887]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:12:40 stefans-speaker sudo[3887]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Sep 01 00:12:40 stefans-speaker sudo[3887]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:12:41 stefans-speaker sudo[3887]: pam_unix(sudo:session): session closed for user root Sep 01 00:12:41 stefans-speaker volumio[3543]: info: Initializing connection to go-librespot Websocket Sep 01 00:12:41 stefans-speaker volumio[3543]: error: Cannot start Volumio Streaming Daemon Sep 01 00:12:41 stefans-speaker volumio[3543]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Sep 01 00:12:41 stefans-speaker volumio[3543]: sudo: unable to resolve host stefans-speaker: System error Sep 01 00:12:41 stefans-speaker volumio[3543]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Sep 01 00:12:41 stefans-speaker volumio[3543]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 00:12:41 stefans-speaker volumio[3543]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Sep 01 00:12:42 stefans-speaker volumio[3543]: info: MyVolumio token set successfully Sep 01 00:12:42 stefans-speaker volumio[3543]: info: MYVOLUMIO: Adding device Sep 01 00:12:42 stefans-speaker volumio[3543]: info: MYVOLUMIO: Evaluating Server Sep 01 00:12:42 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Sep 01 00:12:42 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:12:42 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:12:42 stefans-speaker go-librespot[3901]: go-librespot daemon starting... Sep 01 00:12:42 stefans-speaker go-librespot[3908]: time="2026-09-01T00:12:42+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:12:42 stefans-speaker go-librespot[3908]: time="2026-09-01T00:12:42+02:00" level=debug msg="app state loaded" Sep 01 00:12:42 stefans-speaker go-librespot[3908]: time="2026-09-01T00:12:42+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:12:42 stefans-speaker volumio[3543]: info: MyVolumio status changed Sep 01 00:12:42 stefans-speaker volumio[3543]: info: Streaming services startup Sep 01 00:12:42 stefans-speaker volumio[3543]: info: Starting Streaming Daemon Sep 01 00:12:42 stefans-speaker volumio[3543]: info: Removing browser output: myVolumio user plan is not superstar Sep 01 00:12:42 stefans-speaker volumio[3543]: info: Removing audio output: Sep 01 00:12:42 stefans-speaker volumio[3543]: info: Stoppping Tunnel 1 Sep 01 00:12:42 stefans-speaker sudo[3921]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:12:42 stefans-speaker sudo[3921]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Sep 01 00:12:42 stefans-speaker sudo[3921]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:12:42 stefans-speaker sudo[3923]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:12:42 stefans-speaker sudo[3923]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Sep 01 00:12:42 stefans-speaker sudo[3923]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:12:42 stefans-speaker sudo[3921]: pam_unix(sudo:session): session closed for user root Sep 01 00:12:42 stefans-speaker volumio[3543]: error: Cannot start Volumio Streaming Daemon Sep 01 00:12:42 stefans-speaker volumio[3543]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Sep 01 00:12:42 stefans-speaker volumio[3543]: sudo: unable to resolve host stefans-speaker: System error Sep 01 00:12:42 stefans-speaker volumio[3543]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Sep 01 00:12:42 stefans-speaker systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Sep 01 00:12:42 stefans-speaker systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Sep 01 00:12:42 stefans-speaker systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Sep 01 00:12:42 stefans-speaker systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Sep 01 00:12:42 stefans-speaker systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Sep 01 00:12:42 stefans-speaker systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Sep 01 00:12:42 stefans-speaker systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Sep 01 00:12:42 stefans-speaker systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Sep 01 00:12:42 stefans-speaker sudo[3923]: pam_unix(sudo:session): session closed for user root Sep 01 00:12:42 stefans-speaker volumio[3543]: info: Remote SSH Stopped Sep 01 00:12:42 stefans-speaker go-librespot[3908]: time="2026-09-01T00:12:42+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Sep 01 00:12:42 stefans-speaker go-librespot[3908]: time="2026-09-01T00:12:42+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Sep 01 00:12:42 stefans-speaker go-librespot[3908]: time="2026-09-01T00:12:42+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Sep 01 00:12:42 stefans-speaker go-librespot[3908]: time="2026-09-01T00:12:42+02:00" level=info msg="zeroconf server listening on port 46039" Sep 01 00:12:42 stefans-speaker go-librespot[3908]: time="2026-09-01T00:12:42+02:00" level=debug msg="obtained new client token: AAHdNGj2W++sVEIIcMAtOGlBboDfDTSilkXKiTeP91cU/LJfGUJL2BEz5/7wISKqd5AudNKzpxSzrvDzTndNrq8rNw6SLjZQG/ehbR6uvvsZKOW45u1hAeJ9Q2SWXTrzJtfKvFSeAK/b2mTV+4+b9XvcCDXY1pwP7Ci1t1wj4KfJ8JBcOdTvGrbQx5wtq19ZiSxnkGwsfmq/DHxkm++sWLXbVAG0JXgNAQJGjKEuppnSPhnGSNn6Jy5Q/vg=" Sep 01 00:12:42 stefans-speaker go-librespot[3908]: time="2026-09-01T00:12:42+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 00:12:42 stefans-speaker go-librespot[3908]: time="2026-09-01T00:12:42+02:00" level=debug msg="completed keyexchange" Sep 01 00:12:42 stefans-speaker go-librespot[3908]: time="2026-09-01T00:12:42+02:00" level=debug msg="completed challenge" Sep 01 00:12:42 stefans-speaker go-librespot[3908]: time="2026-09-01T00:12:42+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:12:43 stefans-speaker go-librespot[3908]: time="2026-09-01T00:12:43+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 00:12:43 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:12:43 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:12:44 stefans-speaker volumio[3543]: info: Initializing connection to go-librespot Websocket Sep 01 00:12:44 stefans-speaker volumio[3543]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 00:12:44 stefans-speaker volumio[3543]: info: Setting Geolocation for MyVolumio to eu8 Sep 01 00:12:44 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:12:44 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:12:44 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:12:44 stefans-speaker volumio[3543]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Sep 01 00:12:45 stefans-speaker volumio[3543]: info: Updating MyVolumio device info Sep 01 00:12:45 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:12:45 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:12:45 stefans-speaker volumio[3543]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:12:45 stefans-speaker volumio[3543]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Sep 01 00:12:46 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Sep 01 00:12:46 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:12:46 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:12:46 stefans-speaker go-librespot[3927]: go-librespot daemon starting... Sep 01 00:12:46 stefans-speaker go-librespot[3928]: time="2026-09-01T00:12:46+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:12:46 stefans-speaker go-librespot[3928]: time="2026-09-01T00:12:46+02:00" level=debug msg="app state loaded" Sep 01 00:12:46 stefans-speaker go-librespot[3928]: time="2026-09-01T00:12:46+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:12:46 stefans-speaker go-librespot[3928]: time="2026-09-01T00:12:46+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 00:12:46 stefans-speaker go-librespot[3928]: time="2026-09-01T00:12:46+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 01 00:12:46 stefans-speaker go-librespot[3928]: time="2026-09-01T00:12:46+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 01 00:12:46 stefans-speaker go-librespot[3928]: time="2026-09-01T00:12:46+02:00" level=info msg="zeroconf server listening on port 35395" Sep 01 00:12:46 stefans-speaker go-librespot[3928]: time="2026-09-01T00:12:46+02:00" level=debug msg="obtained new client token: AAHPoxU86Z0Do1Y3zCQmnPyw6m7usdQ/bZnyHoPYqBVgZyO1xiaga4G2oWgrpF2Loo3L3Dr3RLTula8nXQgnjTGIyzpxKkcu1JsYpHkEzUqPEHJ4AmIHggPeAjLLBPE48LmtHZraf1FJzG5H3xwGdy/uM3pvh3BIkQNTUh/S6vAVWlbmNW947CqSq9zVfVL2MVzlxckKtIrHvQa3NZMZeFUgrCrkC8xupNEC1QuN4f0syOMRppVuamRW1qk=" Sep 01 00:12:46 stefans-speaker go-librespot[3928]: time="2026-09-01T00:12:46+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 00:12:46 stefans-speaker go-librespot[3928]: time="2026-09-01T00:12:46+02:00" level=debug msg="completed keyexchange" Sep 01 00:12:46 stefans-speaker go-librespot[3928]: time="2026-09-01T00:12:46+02:00" level=debug msg="completed challenge" Sep 01 00:12:47 stefans-speaker go-librespot[3928]: time="2026-09-01T00:12:47+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:12:47 stefans-speaker volumio[3543]: info: Initializing connection to go-librespot Websocket Sep 01 00:12:47 stefans-speaker go-librespot[3928]: time="2026-09-01T00:12:47+02:00" level=debug msg="new websocket client" Sep 01 00:12:47 stefans-speaker volumio[3543]: info: Connection to go-librespot Websocket established Sep 01 00:12:47 stefans-speaker go-librespot[3928]: time="2026-09-01T00:12:47+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 00:12:47 stefans-speaker volumio[3543]: info: Connection to go-librespot Websocket closed Sep 01 00:12:47 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:12:47 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:12:48 stefans-speaker volumio[3543]: info: MYVOLUMIO: Adding device Sep 01 00:12:48 stefans-speaker volumio[3543]: info: MYVOLUMIO: Evaluating Server Sep 01 00:12:50 stefans-speaker volumio[3543]: info: Getting Spotify volume Sep 01 00:12:50 stefans-speaker volumio[3543]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 01 00:12:50 stefans-speaker volumio[3543]: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 00:12:50 stefans-speaker volumio[3543]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Sep 01 00:12:50 stefans-speaker volumio[3543]: errno: -111, Sep 01 00:12:50 stefans-speaker volumio[3543]: code: 'ECONNREFUSED', Sep 01 00:12:50 stefans-speaker volumio[3543]: syscall: 'connect', Sep 01 00:12:50 stefans-speaker volumio[3543]: address: '127.0.0.1', Sep 01 00:12:50 stefans-speaker volumio[3543]: port: 9879, Sep 01 00:12:50 stefans-speaker volumio[3543]: response: undefined Sep 01 00:12:50 stefans-speaker volumio[3543]: } Sep 01 00:12:50 stefans-speaker volumio[3543]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 01 00:12:50 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Sep 01 00:12:50 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:12:50 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:12:50 stefans-speaker go-librespot[3979]: go-librespot daemon starting... Sep 01 00:12:50 stefans-speaker go-librespot[3980]: time="2026-09-01T00:12:50+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:12:50 stefans-speaker go-librespot[3980]: time="2026-09-01T00:12:50+02:00" level=debug msg="app state loaded" Sep 01 00:12:50 stefans-speaker go-librespot[3980]: time="2026-09-01T00:12:50+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:12:50 stefans-speaker go-librespot[3980]: time="2026-09-01T00:12:50+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 00:12:50 stefans-speaker go-librespot[3980]: time="2026-09-01T00:12:50+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 01 00:12:50 stefans-speaker go-librespot[3980]: time="2026-09-01T00:12:50+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 01 00:12:50 stefans-speaker go-librespot[3980]: time="2026-09-01T00:12:50+02:00" level=info msg="zeroconf server listening on port 36157" Sep 01 00:12:50 stefans-speaker sudo[3989]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:12:50 stefans-speaker sudo[3989]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-09-01 00:11' Sep 01 00:12:50 stefans-speaker sudo[3989]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:12:51 stefans-speaker go-librespot[3980]: time="2026-09-01T00:12:51+02:00" level=debug msg="obtained new client token: AAHyQ9xUk3z7LCOtKN7KVUnu5uqpufgvIEcY0GUxvb+YUcNWS+kf2myCvFtKYjUCRq48f/4ZNBPZiTyZg/F6wfxBZR7cDChvpOqMqFD+EYz5lRo7pn9cT5VafGzUlIaWkc1265CbXJpXGqURJ4EVE/ipXWRx/1jL8tTpseqSPObsp8hAt36gmXAKPH5SRvsIo4MJM5JikJBupTxHPCtreYsllRrHXoqN8a7JfJZmuRqxT4R16lKVBY20" Sep 01 00:12:51 stefans-speaker go-librespot[3980]: time="2026-09-01T00:12:51+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 00:12:51 stefans-speaker go-librespot[3980]: time="2026-09-01T00:12:51+02:00" level=debug msg="completed keyexchange" Sep 01 00:12:51 stefans-speaker go-librespot[3980]: time="2026-09-01T00:12:51+02:00" level=debug msg="completed challenge" Sep 01 00:12:51 stefans-speaker sudo[3989]: pam_unix(sudo:session): session closed for user root Sep 01 00:12:51 stefans-speaker go-librespot[3980]: time="2026-09-01T00:12:51+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:12:51 stefans-speaker volumio[3543]: sudo: unable to resolve host stefans-speaker: System error Sep 01 00:12:51 stefans-speaker volumio-remote-updater[679]: [2026-09-01 00:12:51] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Sep 01 00:12:51 stefans-speaker volumio-remote-updater[679]: [2026-09-01 00:12:51] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Sep 01 00:12:51 stefans-speaker systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:12:51 stefans-speaker systemd[1]: volumio.service: Failed with result 'exit-code'. Sep 01 00:12:51 stefans-speaker systemd[1]: volumio.service: Consumed 32.623s CPU time. Sep 01 00:12:51 stefans-speaker go-librespot[3980]: time="2026-09-01T00:12:51+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 00:12:51 stefans-speaker systemd[1]: Started dynamicswap.service - dynamicswap service. Sep 01 00:12:51 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:12:51 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:12:51 stefans-speaker systemd[1]: dynamicswap.service: Deactivated successfully. Sep 01 00:12:51 stefans-speaker systemd[1]: volumio.service: Scheduled restart job, restart counter is at 211. Sep 01 00:12:51 stefans-speaker systemd[1]: Started dynamicswap.service - dynamicswap service. Sep 01 00:12:51 stefans-speaker systemd[1]: Stopped volumio.service - Volumio Backend Module. Sep 01 00:12:51 stefans-speaker systemd[1]: volumio.service: Consumed 32.623s CPU time. Sep 01 00:12:51 stefans-speaker systemd[1]: Started volumio.service - Volumio Backend Module. Sep 01 00:12:51 stefans-speaker systemd[1]: dynamicswap.service: Deactivated successfully. Sep 01 00:12:53 stefans-speaker volumio[4001]: info: ------------------------------------------- Sep 01 00:12:53 stefans-speaker volumio[4001]: info: ----- Volumio3 ---- Sep 01 00:12:53 stefans-speaker volumio[4001]: info: ------------------------------------------- Sep 01 00:12:53 stefans-speaker volumio[4001]: info: ----- System startup ---- Sep 01 00:12:53 stefans-speaker volumio[4001]: info: ------------------------------------------- Sep 01 00:12:54 stefans-speaker volumio[4001]: info: MYVOLUMIO Environment detected Sep 01 00:12:54 stefans-speaker volumio[4001]: info: Plugin folders cleanup Sep 01 00:12:54 stefans-speaker volumio[4001]: info: Scanning into folder /volumio/app/plugins/ Sep 01 00:12:54 stefans-speaker volumio[4001]: info: Scanning category audio_interface Sep 01 00:12:54 stefans-speaker volumio[4001]: info: Scanning category miscellanea Sep 01 00:12:54 stefans-speaker volumio[4001]: info: Scanning category music_service Sep 01 00:12:54 stefans-speaker volumio[4001]: info: Scanning category plugins.json Sep 01 00:12:54 stefans-speaker volumio[4001]: info: Scanning category system_controller Sep 01 00:12:54 stefans-speaker volumio[4001]: info: Scanning category user_interface Sep 01 00:12:54 stefans-speaker volumio[4001]: info: Scanning into folder /data/plugins/ Sep 01 00:12:54 stefans-speaker volumio[4001]: info: Scanning category music_service Sep 01 00:12:54 stefans-speaker volumio[4001]: info: Plugin folders cleanup completed Sep 01 00:12:54 stefans-speaker volumio[4001]: info: ------------------------------------------- Sep 01 00:12:54 stefans-speaker volumio[4001]: info: ----- Core plugins startup ---- Sep 01 00:12:54 stefans-speaker volumio[4001]: info: ------------------------------------------- Sep 01 00:12:54 stefans-speaker volumio[4001]: info: Loading plugins from folder /volumio/app/plugins/ Sep 01 00:12:54 stefans-speaker volumio[4001]: info: Adding plugin upnp to MyMusic Plugins Sep 01 00:12:54 stefans-speaker volumio[4001]: info: Adding plugin airplay_emulation to MyMusic Plugins Sep 01 00:12:54 stefans-speaker volumio[4001]: info: Adding plugin upnp_browser to MyMusic Plugins Sep 01 00:12:54 stefans-speaker volumio[4001]: info: Loading plugins from folder /data/plugins/ Sep 01 00:12:54 stefans-speaker volumio[4001]: info: Loading plugin "system"... Sep 01 00:12:54 stefans-speaker volumio[4001]: info: Loading plugin "appearance"... Sep 01 00:12:54 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Sep 01 00:12:54 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:12:54 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:12:54 stefans-speaker go-librespot[4031]: go-librespot daemon starting... Sep 01 00:12:54 stefans-speaker go-librespot[4032]: time="2026-09-01T00:12:54+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:12:54 stefans-speaker go-librespot[4032]: time="2026-09-01T00:12:54+02:00" level=debug msg="app state loaded" Sep 01 00:12:54 stefans-speaker go-librespot[4032]: time="2026-09-01T00:12:54+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:12:54 stefans-speaker go-librespot[4032]: time="2026-09-01T00:12:54+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Sep 01 00:12:54 stefans-speaker go-librespot[4032]: time="2026-09-01T00:12:54+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Sep 01 00:12:54 stefans-speaker go-librespot[4032]: time="2026-09-01T00:12:54+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Sep 01 00:12:54 stefans-speaker go-librespot[4032]: time="2026-09-01T00:12:54+02:00" level=info msg="zeroconf server listening on port 40051" Sep 01 00:12:55 stefans-speaker go-librespot[4032]: time="2026-09-01T00:12:55+02:00" level=debug msg="obtained new client token: AAFUhRWVXUoEossIRq2GlJn5FiXyY9QZN8+kl8SYEypM3VndZrbKYSEdliPq+QT2LS081cX4ine2Z3l2Eqo48k+1gQiYdEyEXFnFDjIG6k8xu5FKB6N7cNdXsRfpCk2drXZzK5xl90p9ULHvEQ2uxQbYsr2i6sMb03AGyqs/9O+RWq5tPGBRqyJxXrKXJLv9EMjK3z+YmSVqDfNeVoIdeYNu692WIMIN6q6xHRqsAGGbZ1Gl/iN+ye3Z" Sep 01 00:12:55 stefans-speaker go-librespot[4032]: time="2026-09-01T00:12:55+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 00:12:55 stefans-speaker go-librespot[4032]: time="2026-09-01T00:12:55+02:00" level=debug msg="completed keyexchange" Sep 01 00:12:55 stefans-speaker go-librespot[4032]: time="2026-09-01T00:12:55+02:00" level=debug msg="completed challenge" Sep 01 00:12:55 stefans-speaker go-librespot[4032]: time="2026-09-01T00:12:55+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:12:55 stefans-speaker go-librespot[4032]: time="2026-09-01T00:12:55+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 00:12:55 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:12:55 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:12:55 stefans-speaker volumio[4001]: info: Loading plugin "network"... Sep 01 00:12:55 stefans-speaker volumio[4001]: info: Refreshing Cached IP Addresses Sep 01 00:12:55 stefans-speaker volumio[4001]: info: Loading plugin "services"... Sep 01 00:12:55 stefans-speaker volumio[4001]: info: Loading plugin "alsa_controller"... Sep 01 00:12:55 stefans-speaker sudo[4040]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:12:55 stefans-speaker sudo[4042]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:12:55 stefans-speaker sudo[4042]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 01 00:12:55 stefans-speaker sudo[4042]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:12:55 stefans-speaker sudo[4040]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 01 00:12:55 stefans-speaker sudo[4040]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:12:55 stefans-speaker sudo[4049]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:12:55 stefans-speaker sudo[4042]: pam_unix(sudo:session): session closed for user root Sep 01 00:12:55 stefans-speaker sudo[4040]: pam_unix(sudo:session): session closed for user root Sep 01 00:12:55 stefans-speaker sudo[4049]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Sep 01 00:12:55 stefans-speaker sudo[4049]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:12:55 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 01 00:12:55 stefans-speaker volumio[4001]: info: Loading plugin "wizard"... Sep 01 00:12:55 stefans-speaker volumio[4001]: info: Loading plugin "networkfs"... Sep 01 00:12:55 stefans-speaker volumio[4001]: info: Starting Udev Watcher for removable devices Sep 01 00:12:55 stefans-speaker volumio[4001]: info: Ignoring mount for partition: boot Sep 01 00:12:55 stefans-speaker volumio[4001]: info: Ignoring mount for partition: volumio Sep 01 00:12:55 stefans-speaker volumio[4001]: info: Ignoring mount for partition: volumio_data Sep 01 00:12:55 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 01 00:12:55 stefans-speaker volumio[4001]: info: Loading plugin "volumio_command_line_client"... Sep 01 00:12:55 stefans-speaker volumio[4001]: info: Loading plugin "upnp"... Sep 01 00:12:55 stefans-speaker volumio[4001]: info: [1788214375879] Starting Upmpd Daemon Sep 01 00:12:55 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 01 00:12:55 stefans-speaker volumio[4001]: info: Loading plugin "my_music"... Sep 01 00:12:55 stefans-speaker volumio[4001]: info: Loading plugin "mpd"... Sep 01 00:12:56 stefans-speaker volumio[4001]: info: Loading plugin "upnp_browser"... Sep 01 00:12:56 stefans-speaker volumio-remote-updater[679]: [2026-09-01 00:12:56] [connect] Successful connection Sep 01 00:12:57 stefans-speaker volumio[4001]: info: Starting UPNP Browser Sep 01 00:12:57 stefans-speaker volumio[4001]: info: Loading plugin "alarm-clock"... Sep 01 00:12:57 stefans-speaker volumio[4001]: info: Loading plugin "airplay_emulation"... Sep 01 00:12:57 stefans-speaker volumio[4001]: info: Starting Shairport Sync Sep 01 00:12:57 stefans-speaker volumio[4001]: info: Loading plugin "last_100"... Sep 01 00:12:58 stefans-speaker volumio[4001]: info: Loading plugin "webradio"... Sep 01 00:12:58 stefans-speaker volumio[4001]: info: Loading plugin "i2s_dacs"... Sep 01 00:12:58 stefans-speaker volumio[4001]: info: I2S DAC not set, start Auto-detection Sep 01 00:12:58 stefans-speaker volumio[4001]: info: Loading plugin "volumiodiscovery"... Sep 01 00:12:58 stefans-speaker volumio[4001]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 01 00:12:58 stefans-speaker volumio[4001]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 01 00:12:58 stefans-speaker volumio[4001]: *** WARNING *** For more information see Sep 01 00:12:58 stefans-speaker volumio[4001]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 01 00:12:58 stefans-speaker volumio[4001]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 01 00:12:58 stefans-speaker volumio[4001]: *** WARNING *** For more information see Sep 01 00:12:58 stefans-speaker node[4001]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 01 00:12:58 stefans-speaker node[4001]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 01 00:12:58 stefans-speaker node[4001]: *** WARNING *** For more information see Sep 01 00:12:58 stefans-speaker node[4001]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 01 00:12:58 stefans-speaker node[4001]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 01 00:12:58 stefans-speaker node[4001]: *** WARNING *** For more information see Sep 01 00:12:58 stefans-speaker volumio[4001]: info: Applying required configuration parameters for plugin volumiodiscovery Sep 01 00:12:58 stefans-speaker volumio[4001]: info: Discovery: Started advertising with name: Stefan’s Speaker Sep 01 00:12:58 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 01 00:12:58 stefans-speaker volumio[4001]: info: Loading plugin "spop"... Sep 01 00:12:58 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Sep 01 00:12:58 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:12:58 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:12:58 stefans-speaker go-librespot[4075]: go-librespot daemon starting... Sep 01 00:12:58 stefans-speaker go-librespot[4076]: time="2026-09-01T00:12:58+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:12:58 stefans-speaker go-librespot[4076]: time="2026-09-01T00:12:58+02:00" level=debug msg="app state loaded" Sep 01 00:12:58 stefans-speaker go-librespot[4076]: time="2026-09-01T00:12:58+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:12:59 stefans-speaker sudo[4049]: pam_unix(sudo:session): session closed for user root Sep 01 00:12:59 stefans-speaker go-librespot[4076]: time="2026-09-01T00:12:59+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 00:12:59 stefans-speaker go-librespot[4076]: time="2026-09-01T00:12:59+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 01 00:12:59 stefans-speaker go-librespot[4076]: time="2026-09-01T00:12:59+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 01 00:12:59 stefans-speaker go-librespot[4076]: time="2026-09-01T00:12:59+02:00" level=info msg="zeroconf server listening on port 42795" Sep 01 00:12:59 stefans-speaker volumio[4001]: info: Loading plugin "ytcr"... Sep 01 00:12:59 stefans-speaker go-librespot[4076]: time="2026-09-01T00:12:59+02:00" level=debug msg="obtained new client token: AAFINZR43JKH5Kqhp3jb3WBgHoHTt/LQnTfvAS1rLhFf7Bca/aWwZpgrTR8NHpIaiUAreB14i/I841dhEujyK/P4x6pZqL/dF83DVa1qrOBf/YAQKKhXfd2u3WFl33Y4d6txaM3YnTX6fzM4lNbIM5V0cB+ZiLM1NXQiC90qbDa+y2F2hQ7k5bq0S1sSDcjqP9OWNMwBS67on9IIER+9Ou1eTsZzdIWnCn4eflzxW5WbLcoxTHolAQ5ZERE=" Sep 01 00:12:59 stefans-speaker go-librespot[4076]: time="2026-09-01T00:12:59+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Sep 01 00:13:00 stefans-speaker go-librespot[4076]: time="2026-09-01T00:13:00+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Sep 01 00:13:00 stefans-speaker go-librespot[4076]: time="2026-09-01T00:13:00+02:00" level=debug msg="completed keyexchange" Sep 01 00:13:00 stefans-speaker go-librespot[4076]: time="2026-09-01T00:13:00+02:00" level=debug msg="completed challenge" Sep 01 00:13:00 stefans-speaker go-librespot[4076]: time="2026-09-01T00:13:00+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:13:00 stefans-speaker go-librespot[4076]: time="2026-09-01T00:13:00+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 00:13:00 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:13:00 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:13:00 stefans-speaker volumio[4001]: info: Loading plugin "outputs"... Sep 01 00:13:00 stefans-speaker volumio[4001]: info: Loading plugin "albumart"... Sep 01 00:13:00 stefans-speaker volumio[4001]: info: Plugin example_plugin is not enabled Sep 01 00:13:00 stefans-speaker volumio[4001]: info: Loading plugin "inputs"... Sep 01 00:13:00 stefans-speaker volumio[4001]: info: Loading plugin "updater_comm"... Sep 01 00:13:00 stefans-speaker volumio[4001]: info: Plugin mpdemulation is not enabled Sep 01 00:13:00 stefans-speaker volumio[4001]: info: Loading plugin "rest_api"... Sep 01 00:13:00 stefans-speaker volumio[4001]: info: Loading plugin "websocket"... Sep 01 00:13:00 stefans-speaker volumio[4001]: info: Starting Socket.io Server version 1.7.4 Sep 01 00:13:01 stefans-speaker volumio[4001]: info: Loading i18n strings for locale nl Sep 01 00:13:01 stefans-speaker volumio[4001]: Updating browse sources language Sep 01 00:13:01 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 00:13:01 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 00:13:01 stefans-speaker volumio[4001]: info: CoreCommandRouter::initPlayerControls Sep 01 00:13:01 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:01 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:01 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:01 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:01 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:01 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:01 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:01 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:01 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 00:13:01 stefans-speaker volumio[4001]: Express server listening on port 3000 Sep 01 00:13:01 stefans-speaker volumio[4001]: [Metrics] WebUI: 8s 150.74ms Sep 01 00:13:01 stefans-speaker volumio[4001]: info: CoreStateMachine::resetVolumioState Sep 01 00:13:01 stefans-speaker volumio[4001]: info: CoreStateMachine::getcurrentVolume Sep 01 00:13:01 stefans-speaker volumio[4001]: info: CoreCommandRouter::volumioRetrievevolume Sep 01 00:13:01 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:13:01 stefans-speaker volumio[4001]: info: Cannot read play queue from file Sep 01 00:13:01 stefans-speaker volumio[4001]: info: Volumio Network Manager: Network status updated: 2 Sep 01 00:13:01 stefans-speaker volumio[4084]: Forking 3 albumart workers Sep 01 00:13:01 stefans-speaker volumio[4001]: info: VolumeController:: Volume=70 Mute =false Sep 01 00:13:01 stefans-speaker volumio[4001]: info: CoreStateMachine::pushState Sep 01 00:13:01 stefans-speaker volumio[4001]: info: CorePlayQueue::getTrack 0 Sep 01 00:13:01 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 01 00:13:01 stefans-speaker volumio[4001]: info: CoreCommandRouter::volumioPushState Sep 01 00:13:01 stefans-speaker volumio[4001]: info: CoreStateMachine::updateTrackBlock Sep 01 00:13:01 stefans-speaker volumio[4001]: info: CorePlayQueue::getTrackBlock Sep 01 00:13:01 stefans-speaker volumio[4001]: info: CoreCommandRouter::volumioRetrievevolume Sep 01 00:13:01 stefans-speaker volumio[4001]: info: CoreStateMachine::setRepeat null single undefined Sep 01 00:13:01 stefans-speaker volumio[4001]: info: CoreStateMachine::pushState Sep 01 00:13:01 stefans-speaker volumio[4001]: info: CorePlayQueue::getTrack 0 Sep 01 00:13:01 stefans-speaker volumio[4001]: info: CoreCommandRouter::volumioPushState Sep 01 00:13:01 stefans-speaker volumio[4001]: info: CoreStateMachine::setRandom null Sep 01 00:13:01 stefans-speaker volumio[4001]: info: CoreStateMachine::pushState Sep 01 00:13:01 stefans-speaker volumio[4001]: info: CorePlayQueue::getTrack 0 Sep 01 00:13:01 stefans-speaker volumio[4001]: info: CoreCommandRouter::volumioPushState Sep 01 00:13:01 stefans-speaker volumio[4001]: info: Setting Device type: Raspberry PI Sep 01 00:13:01 stefans-speaker volumio[4001]: info: VolumeController:: Volume=70 Mute =false Sep 01 00:13:01 stefans-speaker volumio[4001]: info: CoreStateMachine::pushState Sep 01 00:13:01 stefans-speaker volumio[4001]: info: CorePlayQueue::getTrack 0 Sep 01 00:13:01 stefans-speaker volumio[4001]: info: CoreCommandRouter::volumioPushState Sep 01 00:13:01 stefans-speaker volumio[4001]: info: Completed loading Core Plugins Sep 01 00:13:01 stefans-speaker volumio[4001]: info: Preparing to generate the ALSA configuration file Sep 01 00:13:01 stefans-speaker volumio[4001]: info: Asound.conf file unchanged, so no further update is needed Sep 01 00:13:01 stefans-speaker volumio[4001]: info: Output device has changed, restarting MPD Sep 01 00:13:01 stefans-speaker volumio[4001]: info: Output device has changed, restarting Shairport Sync Sep 01 00:13:01 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:01 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:13:01 stefans-speaker volumio[4001]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 01 00:13:01 stefans-speaker volumio[4001]: info: ___________ START PLUGINS ___________ Sep 01 00:13:01 stefans-speaker sudo[4138]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:13:01 stefans-speaker volumio[4001]: info: ControllerMpd::onStart: Initializing MPD Sep 01 00:13:01 stefans-speaker volumio[4001]: info: Creating MPD Configuration file Sep 01 00:13:01 stefans-speaker sudo[4140]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:13:01 stefans-speaker sudo[4138]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 01 00:13:01 stefans-speaker sudo[4138]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:13:01 stefans-speaker sudo[4140]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 01 00:13:01 stefans-speaker sudo[4140]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:13:02 stefans-speaker sudo[4138]: pam_unix(sudo:session): session closed for user root Sep 01 00:13:02 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 00:13:02 stefans-speaker volumio[4001]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 01 00:13:02 stefans-speaker volumio[4001]: info: [1788214382012] CoreMusicLibrary::Adding element Media Servers Sep 01 00:13:02 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 00:13:02 stefans-speaker volumio[4001]: info: UPNP Browser: Client initialized successfully Sep 01 00:13:02 stefans-speaker sudo[4147]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:13:02 stefans-speaker sudo[4150]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:13:02 stefans-speaker sudo[4150]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 01 00:13:02 stefans-speaker systemd[1]: Stopping mpd.service - Music Player Daemon... Sep 01 00:13:02 stefans-speaker sudo[4150]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:13:02 stefans-speaker sudo[4147]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 01 00:13:02 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:02 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:13:02 stefans-speaker sudo[4147]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:13:02 stefans-speaker systemd[1]: mpd.service: Deactivated successfully. Sep 01 00:13:02 stefans-speaker systemd[1]: Stopped mpd.service - Music Player Daemon. Sep 01 00:13:02 stefans-speaker systemd[1]: mpd.service: Consumed 4.457s CPU time. Sep 01 00:13:02 stefans-speaker systemd[1]: mpd.socket: Deactivated successfully. Sep 01 00:13:02 stefans-speaker sudo[4147]: pam_unix(sudo:session): session closed for user root Sep 01 00:13:02 stefans-speaker systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Sep 01 00:13:02 stefans-speaker systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Sep 01 00:13:02 stefans-speaker volumio[4001]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 01 00:13:02 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:02 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:13:02 stefans-speaker volumio[4001]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 01 00:13:02 stefans-speaker systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Sep 01 00:13:02 stefans-speaker volumio[4001]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 01 00:13:02 stefans-speaker volumio[4001]: info: [1788214382235] CoreMusicLibrary::Adding element Last_100 Sep 01 00:13:02 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 00:13:02 stefans-speaker volumio[4001]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 01 00:13:02 stefans-speaker volumio[4001]: info: [1788214382250] CoreMusicLibrary::Adding element Webradio Sep 01 00:13:02 stefans-speaker systemd[1]: Starting mpd.service - Music Player Daemon... Sep 01 00:13:02 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 00:13:02 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 01 00:13:02 stefans-speaker systemd[1]: mpd.service: Deactivated successfully. Sep 01 00:13:02 stefans-speaker systemd[1]: Stopped mpd.service - Music Player Daemon. Sep 01 00:13:02 stefans-speaker systemd[1]: mpd.socket: Deactivated successfully. Sep 01 00:13:02 stefans-speaker systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Sep 01 00:13:02 stefans-speaker systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Sep 01 00:13:02 stefans-speaker volumio[4001]: info: Initializing BBC Radios Sep 01 00:13:02 stefans-speaker systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Sep 01 00:13:02 stefans-speaker systemd[1]: Starting mpd.service - Music Player Daemon... Sep 01 00:13:02 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 01 00:13:02 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:13:02 stefans-speaker volumio[4001]: info: Creating Spotify config file Sep 01 00:13:02 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:02 stefans-speaker sudo[4167]: root : unable to resolve host stefans-speaker: System error Sep 01 00:13:02 stefans-speaker sudo[4167]: sudo: unable to resolve host stefans-speaker: System error Sep 01 00:13:02 stefans-speaker sudo[4167]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Sep 01 00:13:02 stefans-speaker sudo[4167]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Sep 01 00:13:02 stefans-speaker sudo[4167]: pam_unix(sudo:session): session closed for user root Sep 01 00:13:03 stefans-speaker volumio[4001]: info: Volumio Calling Home Sep 01 00:13:03 stefans-speaker volumio[4101]: Starting albumart workers Sep 01 00:13:03 stefans-speaker volumio[4001]: info: Discovery: adding a312d0fa-c0eb-45ad-a25b-79fcdf237e8a Sep 01 00:13:03 stefans-speaker volumio[4001]: info: Discovery: Found device Stefan’s Speaker Sep 01 00:13:03 stefans-speaker volumio[4001]: info: CoreCommandRouter::volumioGetState Sep 01 00:13:03 stefans-speaker volumio[4001]: info: CorePlayQueue::getTrack 0 Sep 01 00:13:03 stefans-speaker volumio[4001]: info: Discovery: this is already registered, a312d0fa-c0eb-45ad-a25b-79fcdf237e8a Sep 01 00:13:03 stefans-speaker volumio[4001]: info: Discovery: Found device Stefan’s Speaker Sep 01 00:13:03 stefans-speaker volumio[4001]: info: CoreCommandRouter::volumioGetState Sep 01 00:13:03 stefans-speaker volumio[4001]: info: CorePlayQueue::getTrack 0 Sep 01 00:13:03 stefans-speaker volumio[4100]: Starting albumart workers Sep 01 00:13:03 stefans-speaker volumio[4001]: info: MPD Permissions set Sep 01 00:13:03 stefans-speaker volumio[4001]: info: MPD Permissions set Sep 01 00:13:03 stefans-speaker volumio[4001]: info: Volumio called home Sep 01 00:13:03 stefans-speaker volumio[4001]: info: Spotify config file written Sep 01 00:13:03 stefans-speaker volumio[4001]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Sep 01 00:13:03 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:03 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:03 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:03 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:03 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:03 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:03 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:03 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:03 stefans-speaker volumio[4099]: Starting albumart workers Sep 01 00:13:03 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:13:03 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:03 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:03 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:03 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:03 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:03 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:03 stefans-speaker sudo[4184]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:13:03 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:03 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:03 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:03 stefans-speaker sudo[4184]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Sep 01 00:13:03 stefans-speaker sudo[4184]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:13:03 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Sep 01 00:13:03 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:13:03 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:03 stefans-speaker volumio[4001]: info: No need to fix Spotify hosts Sep 01 00:13:03 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:13:03 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:13:03 stefans-speaker go-librespot[4196]: go-librespot daemon starting... Sep 01 00:13:03 stefans-speaker systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Sep 01 00:13:03 stefans-speaker systemd[1]: go-librespot-daemon.service: Deactivated successfully. Sep 01 00:13:03 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:13:03 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:13:03 stefans-speaker go-librespot[4202]: go-librespot daemon starting... Sep 01 00:13:03 stefans-speaker sudo[4184]: pam_unix(sudo:session): session closed for user root Sep 01 00:13:03 stefans-speaker go-librespot[4203]: time="2026-09-01T00:13:03+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:13:03 stefans-speaker go-librespot[4203]: time="2026-09-01T00:13:03+02:00" level=debug msg="app state loaded" Sep 01 00:13:03 stefans-speaker go-librespot[4203]: time="2026-09-01T00:13:03+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:13:04 stefans-speaker go-librespot[4203]: time="2026-09-01T00:13:04+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 00:13:04 stefans-speaker go-librespot[4203]: time="2026-09-01T00:13:04+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 01 00:13:04 stefans-speaker go-librespot[4203]: time="2026-09-01T00:13:04+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 01 00:13:04 stefans-speaker go-librespot[4203]: time="2026-09-01T00:13:04+02:00" level=info msg="zeroconf server listening on port 45385" Sep 01 00:13:04 stefans-speaker go-librespot[4203]: time="2026-09-01T00:13:04+02:00" level=debug msg="obtained new client token: AAEmbvVIJue2mmSpFwNniz8JsnxIoM9P574LPPf7SpxaQAnDTMLqg7LXj+xMMLKxa2uo6OFTqCfKFMIh/hBMbCv1XAnjR36TC0szqMVp0m/+/6kNZHx4Z0SbCgf/GXaSjNEYUWT2Lzg0IEBSSthSNRFvOGP887s38TnOhhHfaYNsF//UmxOABxVK9hehbwBu7VRCCHn8gnkPOHxcxYPlR5pp5zkk6QQXkdG8TP1Y5zzJmBHyD51Ceuqh89o=" Sep 01 00:13:04 stefans-speaker go-librespot[4203]: time="2026-09-01T00:13:04+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 00:13:04 stefans-speaker go-librespot[4203]: time="2026-09-01T00:13:04+02:00" level=debug msg="completed keyexchange" Sep 01 00:13:04 stefans-speaker go-librespot[4203]: time="2026-09-01T00:13:04+02:00" level=debug msg="completed challenge" Sep 01 00:13:04 stefans-speaker go-librespot[4203]: time="2026-09-01T00:13:04+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:13:04 stefans-speaker volumio[4001]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Sep 01 00:13:04 stefans-speaker volumio[4001]: SPOTIFY: BQAybwz_7FYuka7wsiJbCLKnvb1O-2WlViDXqG276JfYvfLYwMIR1pkKFimedBHNOY9klT6rLZYe626sW2ibmevJxga9rOFnEM1MDjFTiE6AD3jYjyUseKOkUxHYtX-bxuhrUJCwv7JKIO-Ci060UjVb6MXPL3ukVwV52NczjPFakOs9bWu82Z2v2A6YMFI6y4CwpU68VBueENMnFlg0WyqHhTwrbGwFBM9YcqtcbMUVH8ACcyRjm9GHm2XmhIyz2hrBEH7uTPKj-EWOdzsciEZhv3eUzAaKW3Y75ZMpWhir7vZdLGnPsghn3-34RdU Sep 01 00:13:04 stefans-speaker volumio[4001]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Sep 01 00:13:04 stefans-speaker volumio[4001]: info: New Spotify access token = BQAybwz_7FYuka7wsiJbCLKnvb1O-2WlViDXqG276JfYvfLYwMIR1pkKFimedBHNOY9klT6rLZYe626sW2ibmevJxga9rOFnEM1MDjFTiE6AD3jYjyUseKOkUxHYtX-bxuhrUJCwv7JKIO-Ci060UjVb6MXPL3ukVwV52NczjPFakOs9bWu82Z2v2A6YMFI6y4CwpU68VBueENMnFlg0WyqHhTwrbGwFBM9YcqtcbMUVH8ACcyRjm9GHm2XmhIyz2hrBEH7uTPKj-EWOdzsciEZhv3eUzAaKW3Y75ZMpWhir7vZdLGnPsghn3-34RdU Sep 01 00:13:04 stefans-speaker volumio[4001]: info: Spotify credentials grant success - running version from March 24, 2019 Sep 01 00:13:04 stefans-speaker go-librespot[4203]: time="2026-09-01T00:13:04+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 00:13:04 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:13:04 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:13:05 stefans-speaker volumio[4001]: info: Starting Shairport Sync Sep 01 00:13:05 stefans-speaker volumio[4001]: info: Starting Shairport Sync Sep 01 00:13:05 stefans-speaker volumio[4001]: info: Starting Shairport Sync Sep 01 00:13:05 stefans-speaker sudo[4223]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:13:05 stefans-speaker sudo[4223]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 01 00:13:05 stefans-speaker sudo[4223]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:13:05 stefans-speaker sudo[4225]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:13:05 stefans-speaker sudo[4225]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 01 00:13:05 stefans-speaker sudo[4225]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:13:05 stefans-speaker sudo[4228]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:13:05 stefans-speaker sudo[4228]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 01 00:13:05 stefans-speaker sudo[4228]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:13:05 stefans-speaker systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Sep 01 00:13:05 stefans-speaker systemd[1]: shairport-sync.service: Deactivated successfully. Sep 01 00:13:05 stefans-speaker systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Sep 01 00:13:05 stefans-speaker systemd[1]: shairport-sync.service: Consumed 1.891s CPU time. Sep 01 00:13:05 stefans-speaker systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Sep 01 00:13:05 stefans-speaker sudo[4223]: pam_unix(sudo:session): session closed for user root Sep 01 00:13:05 stefans-speaker systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Sep 01 00:13:05 stefans-speaker systemd[1]: shairport-sync.service: Deactivated successfully. Sep 01 00:13:05 stefans-speaker systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Sep 01 00:13:05 stefans-speaker systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Sep 01 00:13:05 stefans-speaker sudo[4225]: pam_unix(sudo:session): session closed for user root Sep 01 00:13:05 stefans-speaker sudo[4228]: pam_unix(sudo:session): session closed for user root Sep 01 00:13:05 stefans-speaker volumio[4001]: info: Shairport-Sync Started Sep 01 00:13:05 stefans-speaker volumio[4001]: Error adding Membership: Error: addMembership EINVAL Sep 01 00:13:05 stefans-speaker volumio[4001]: info: Shairport-Sync Started Sep 01 00:13:05 stefans-speaker volumio[4001]: info: Shairport-Sync Started Sep 01 00:13:05 stefans-speaker volumio[4001]: info: CoreCommandRouter::volumioGetState Sep 01 00:13:05 stefans-speaker volumio[4001]: info: CorePlayQueue::getTrack 0 Sep 01 00:13:05 stefans-speaker volumio[4001]: SPOTIFY: User informations: {"account_id":"zltuAJDW9c","country":"RO","display_name":"emanueluss","email":"emanuel.grecescu@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31mmtxvuufe76qdkk6caepwk3fcy"},"followers":{"href":null,"total":3},"href":"https://api.spotify.com/v1/users/31mmtxvuufe76qdkk6caepwk3fcy","id":"31mmtxvuufe76qdkk6caepwk3fcy","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee852e7ddfcb02af85c1462f3412","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b822e7ddfcb02af85c1462f3412","width":64}],"product":"premium","type":"user","uri":"spotify:user:31mmtxvuufe76qdkk6caepwk3fcy"} Sep 01 00:13:05 stefans-speaker volumio[4001]: info: Spotify Successfully logged in Sep 01 00:13:05 stefans-speaker volumio[4001]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 01 00:13:05 stefans-speaker volumio[4001]: info: [1788214385628] CoreMusicLibrary::Adding element Spotify Sep 01 00:13:05 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 00:13:05 stefans-speaker volumio[4001]: Cannot find translation for source Spotify Sep 01 00:13:05 stefans-speaker sudo[4270]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:13:05 stefans-speaker sudo[4270]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 01 00:13:05 stefans-speaker sudo[4270]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:13:05 stefans-speaker sudo[4270]: pam_unix(sudo:session): session closed for user root Sep 01 00:13:06 stefans-speaker volumio[4001]: info: [yt-cast-receiver] DIAL server listening on port 8098 Sep 01 00:13:06 stefans-speaker sudo[4272]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:13:06 stefans-speaker volumio[4001]: info: CoreCommandRouter::volumioRetrievevolume Sep 01 00:13:06 stefans-speaker sudo[4272]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 01 00:13:06 stefans-speaker sudo[4272]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:13:06 stefans-speaker sudo[4272]: pam_unix(sudo:session): session closed for user root Sep 01 00:13:06 stefans-speaker sudo[4275]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:13:06 stefans-speaker sudo[4275]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Sep 01 00:13:06 stefans-speaker sudo[4275]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:13:06 stefans-speaker sudo[4275]: pam_unix(sudo:session): session closed for user root Sep 01 00:13:06 stefans-speaker volumio[4001]: info: Upmpdcli Daemon Started Sep 01 00:13:06 stefans-speaker volumio[4001]: info: VolumeController:: Volume=70 Mute =false Sep 01 00:13:06 stefans-speaker volumio[4001]: info: CoreCommandRouter::volumioGetState Sep 01 00:13:06 stefans-speaker volumio[4001]: info: CorePlayQueue::getTrack 0 Sep 01 00:13:06 stefans-speaker volumio[4001]: info: CoreStateMachine::pushState Sep 01 00:13:06 stefans-speaker volumio[4001]: info: CorePlayQueue::getTrack 0 Sep 01 00:13:06 stefans-speaker volumio[4001]: info: CoreCommandRouter::volumioPushState Sep 01 00:13:07 stefans-speaker mpd[4179]: 2026-09-01T00:13:07 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Sep 01 00:13:07 stefans-speaker systemd[1]: Started mpd.service - Music Player Daemon. Sep 01 00:13:07 stefans-speaker sudo[4150]: pam_unix(sudo:session): session closed for user root Sep 01 00:13:07 stefans-speaker sudo[4140]: pam_unix(sudo:session): session closed for user root Sep 01 00:13:07 stefans-speaker volumio[4001]: error: MPD error: The expression evaluated to a falsy value: Sep 01 00:13:07 stefans-speaker volumio[4001]: assert.ok(self.idling) Sep 01 00:13:07 stefans-speaker volumio[4001]: error: The expression evaluated to a falsy value: Sep 01 00:13:07 stefans-speaker volumio[4001]: assert.ok(self.idling) Sep 01 00:13:07 stefans-speaker volumio[4001]: info: MPD running with PID4179 Sep 01 00:13:07 stefans-speaker volumio[4001]: ,establishing connection Sep 01 00:13:07 stefans-speaker volumio[4001]: error: updateQueue error: null Sep 01 00:13:07 stefans-speaker volumio[4001]: info: Completed starting Core Plugins Sep 01 00:13:07 stefans-speaker volumio[4001]: info: ------------------------------------------- Sep 01 00:13:07 stefans-speaker volumio[4001]: info: ----- MyVolumio plugins startup ---- Sep 01 00:13:07 stefans-speaker volumio[4001]: info: ------------------------------------------- Sep 01 00:13:07 stefans-speaker volumio[4001]: info: [MyVolumio PluginManager] Fetching plans data.... Sep 01 00:13:07 stefans-speaker volumio[4001]: error: updateQueue error: null Sep 01 00:13:07 stefans-speaker volumio[4001]: info: go-librespot daemon successfully initialized Sep 01 00:13:08 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Sep 01 00:13:08 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:13:08 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:13:08 stefans-speaker go-librespot[4286]: go-librespot daemon starting... Sep 01 00:13:08 stefans-speaker go-librespot[4287]: time="2026-09-01T00:13:08+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:13:08 stefans-speaker go-librespot[4287]: time="2026-09-01T00:13:08+02:00" level=debug msg="app state loaded" Sep 01 00:13:08 stefans-speaker go-librespot[4287]: time="2026-09-01T00:13:08+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:13:08 stefans-speaker go-librespot[4287]: time="2026-09-01T00:13:08+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 00:13:08 stefans-speaker go-librespot[4287]: time="2026-09-01T00:13:08+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 01 00:13:08 stefans-speaker go-librespot[4287]: time="2026-09-01T00:13:08+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 01 00:13:08 stefans-speaker go-librespot[4287]: time="2026-09-01T00:13:08+02:00" level=info msg="zeroconf server listening on port 34067" Sep 01 00:13:08 stefans-speaker go-librespot[4287]: time="2026-09-01T00:13:08+02:00" level=debug msg="obtained new client token: AAFBoitftypqMsdHPBCB/M/N/1LM2qwqM1I04bb/FlcFAGSBmDNuNVlxvfYKigxZg6RteLsA1C1vN9dBXKwQlmoXoZDOQybxMT8Mo2ewinvMuNJJdf1cAeYUnEd7xs8C1bFjpvwU0wZRo/ewDM+F0ML1AQ6wBpFsa4XZjT+tkn/kEMMM3kTBmJleOQgoPH9dT6oceg4aMV1ZFC+7iFQgdn0srl/HhZdHDq5Gmi2nActYtqipMM3Yh5duHtk=" Sep 01 00:13:08 stefans-speaker go-librespot[4287]: time="2026-09-01T00:13:08+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 00:13:08 stefans-speaker go-librespot[4287]: time="2026-09-01T00:13:08+02:00" level=debug msg="completed keyexchange" Sep 01 00:13:08 stefans-speaker go-librespot[4287]: time="2026-09-01T00:13:08+02:00" level=debug msg="completed challenge" Sep 01 00:13:08 stefans-speaker go-librespot[4287]: time="2026-09-01T00:13:08+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:13:08 stefans-speaker go-librespot[4287]: time="2026-09-01T00:13:08+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 00:13:08 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:13:08 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:13:08 stefans-speaker volumio-remote-updater[679]: [2026-09-01 00:13:08] [connect] Successful connection Sep 01 00:13:08 stefans-speaker volumio-remote-updater[679]: [2026-09-01 00:13:08] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1788214388 101 Sep 01 00:13:08 stefans-speaker volumio[4001]: 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: 2 Sep 01 00:13:10 stefans-speaker sudo[4297]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:13:10 stefans-speaker sudo[4297]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Sep 01 00:13:10 stefans-speaker sudo[4297]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:13:10 stefans-speaker sudo[4299]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:13:10 stefans-speaker sudo[4299]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Sep 01 00:13:10 stefans-speaker sudo[4299]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:13:10 stefans-speaker systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Sep 01 00:13:10 stefans-speaker systemd[1]: mpd_monitor.service: Deactivated successfully. Sep 01 00:13:10 stefans-speaker systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Sep 01 00:13:10 stefans-speaker systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Sep 01 00:13:10 stefans-speaker sudo[4299]: pam_unix(sudo:session): session closed for user root Sep 01 00:13:10 stefans-speaker sudo[4297]: pam_unix(sudo:session): session closed for user root Sep 01 00:13:10 stefans-speaker mpd_monitor.sh[4302]: MPD Monitor Service: Starting MPD Monitor Service Sep 01 00:13:10 stefans-speaker volumio[4001]: info: Successfully started MPD Monitor Sep 01 00:13:10 stefans-speaker volumio[4001]: info: Successfully started MPD Monitor Sep 01 00:13:10 stefans-speaker volumio[4001]: info: Initializing connection to go-librespot Websocket Sep 01 00:13:10 stefans-speaker volumio[4001]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 00:13:11 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Sep 01 00:13:11 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:13:11 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:13:11 stefans-speaker go-librespot[4306]: go-librespot daemon starting... Sep 01 00:13:11 stefans-speaker go-librespot[4307]: time="2026-09-01T00:13:11+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:13:11 stefans-speaker go-librespot[4307]: time="2026-09-01T00:13:11+02:00" level=debug msg="app state loaded" Sep 01 00:13:11 stefans-speaker go-librespot[4307]: time="2026-09-01T00:13:11+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:13:12 stefans-speaker go-librespot[4307]: time="2026-09-01T00:13:12+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 00:13:12 stefans-speaker go-librespot[4307]: time="2026-09-01T00:13:12+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 01 00:13:12 stefans-speaker go-librespot[4307]: time="2026-09-01T00:13:12+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 01 00:13:12 stefans-speaker go-librespot[4307]: time="2026-09-01T00:13:12+02:00" level=info msg="zeroconf server listening on port 46129" Sep 01 00:13:12 stefans-speaker volumio[4001]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Sep 01 00:13:12 stefans-speaker go-librespot[4307]: time="2026-09-01T00:13:12+02:00" level=debug msg="obtained new client token: AAFcf8xxI2AmKI1wCUtioJCXGNG6FGmMcZqZ3cFbtN8wMk4/WMePlgsQNV/6+j2bflghAX12AdSYCvkruNINYunp+kM/wqUqf4UQGBL3LlAlEIUAOXRwzewky6vOsx/O3uujwjcSUV8EMLSCB9BOFoOXihovRXKWbhcmLcW1h91cfbcjQUUhy1VesiONT3/rTtYRW+PO2cPwHSXKxhmpKa7xCRz/TXJUd2ULT0J9VnnMCC/RaUm2DLCL" Sep 01 00:13:12 stefans-speaker go-librespot[4307]: time="2026-09-01T00:13:12+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 00:13:12 stefans-speaker go-librespot[4307]: time="2026-09-01T00:13:12+02:00" level=debug msg="completed keyexchange" Sep 01 00:13:12 stefans-speaker go-librespot[4307]: time="2026-09-01T00:13:12+02:00" level=debug msg="completed challenge" Sep 01 00:13:12 stefans-speaker go-librespot[4307]: time="2026-09-01T00:13:12+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:13:12 stefans-speaker go-librespot[4307]: time="2026-09-01T00:13:12+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 00:13:12 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:13:12 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:13:13 stefans-speaker volumio[4001]: info: Initializing connection to go-librespot Websocket Sep 01 00:13:13 stefans-speaker volumio[4001]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 00:13:15 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Sep 01 00:13:15 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:13:15 stefans-speaker volumio[4001]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Sep 01 00:13:15 stefans-speaker volumio[4001]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Sep 01 00:13:15 stefans-speaker volumio[4001]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Sep 01 00:13:15 stefans-speaker volumio[4001]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Sep 01 00:13:15 stefans-speaker volumio[4001]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Sep 01 00:13:15 stefans-speaker volumio[4001]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Sep 01 00:13:15 stefans-speaker volumio[4001]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Sep 01 00:13:15 stefans-speaker volumio[4001]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Sep 01 00:13:15 stefans-speaker volumio[4001]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Sep 01 00:13:15 stefans-speaker volumio[4001]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Sep 01 00:13:15 stefans-speaker volumio[4001]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Sep 01 00:13:15 stefans-speaker volumio[4001]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Sep 01 00:13:15 stefans-speaker volumio[4001]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Sep 01 00:13:15 stefans-speaker volumio[4001]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Sep 01 00:13:15 stefans-speaker volumio[4001]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Sep 01 00:13:15 stefans-speaker volumio[4001]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Sep 01 00:13:15 stefans-speaker volumio[4001]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Sep 01 00:13:15 stefans-speaker volumio[4001]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Sep 01 00:13:15 stefans-speaker volumio[4001]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Sep 01 00:13:15 stefans-speaker volumio[4001]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Sep 01 00:13:15 stefans-speaker volumio[4001]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Sep 01 00:13:15 stefans-speaker volumio[4001]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Sep 01 00:13:15 stefans-speaker volumio[4001]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Sep 01 00:13:15 stefans-speaker volumio[4001]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Sep 01 00:13:15 stefans-speaker volumio[4001]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Sep 01 00:13:15 stefans-speaker volumio[4001]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Sep 01 00:13:15 stefans-speaker volumio[4001]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Sep 01 00:13:15 stefans-speaker volumio[4001]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Sep 01 00:13:15 stefans-speaker volumio[4001]: info: Adding plugin bluetooth to MyMusic Plugins Sep 01 00:13:15 stefans-speaker volumio[4001]: info: Adding plugin multiroom to MyMusic Plugins Sep 01 00:13:15 stefans-speaker volumio[4001]: info: Adding plugin metavolumio to MyMusic Plugins Sep 01 00:13:15 stefans-speaker volumio[4001]: info: Adding plugin cd_controller to MyMusic Plugins Sep 01 00:13:15 stefans-speaker volumio[4001]: info: Adding plugin qobuzconnect to MyMusic Plugins Sep 01 00:13:15 stefans-speaker volumio[4001]: info: Adding plugin smart_inputs to MyMusic Plugins Sep 01 00:13:15 stefans-speaker volumio[4001]: info: Adding plugin tidalconnect to MyMusic Plugins Sep 01 00:13:15 stefans-speaker volumio[4001]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Sep 01 00:13:15 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:13:15 stefans-speaker go-librespot[4315]: go-librespot daemon starting... Sep 01 00:13:15 stefans-speaker go-librespot[4316]: time="2026-09-01T00:13:15+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:13:15 stefans-speaker go-librespot[4316]: time="2026-09-01T00:13:15+02:00" level=debug msg="app state loaded" Sep 01 00:13:15 stefans-speaker go-librespot[4316]: time="2026-09-01T00:13:15+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:13:15 stefans-speaker go-librespot[4316]: time="2026-09-01T00:13:15+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Sep 01 00:13:15 stefans-speaker go-librespot[4316]: time="2026-09-01T00:13:15+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Sep 01 00:13:15 stefans-speaker go-librespot[4316]: time="2026-09-01T00:13:15+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Sep 01 00:13:15 stefans-speaker go-librespot[4316]: time="2026-09-01T00:13:15+02:00" level=info msg="zeroconf server listening on port 40673" Sep 01 00:13:16 stefans-speaker go-librespot[4316]: time="2026-09-01T00:13:16+02:00" level=debug msg="obtained new client token: AAFf0BF547pOLs6yxbeNf/KT07Z0vJMY0fMkaKhoS8x8ZVY/dlby1ySMWhFyym4y0+0KtM+6Huij+jfAsSjdgBehR0dwMLIzucQRWjuWmCp8ypdtZiwKfhKnqt8NUZ50kloSfdom2fu0Mqd3M9IfH5z8gxZqMaRid1BbeglfoQxC0h3f1Fq5Ht4i2JzA3qqfxi18sacyAuRUkgXfG2zhCNEqCZWBkm52dLQ9LXDANYuB1m80n8zkT5xBnMI=" Sep 01 00:13:16 stefans-speaker go-librespot[4316]: time="2026-09-01T00:13:16+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 00:13:16 stefans-speaker go-librespot[4316]: time="2026-09-01T00:13:16+02:00" level=debug msg="completed keyexchange" Sep 01 00:13:16 stefans-speaker go-librespot[4316]: time="2026-09-01T00:13:16+02:00" level=debug msg="completed challenge" Sep 01 00:13:16 stefans-speaker go-librespot[4316]: time="2026-09-01T00:13:16+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:13:16 stefans-speaker go-librespot[4316]: time="2026-09-01T00:13:16+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 00:13:16 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:13:16 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:13:16 stefans-speaker volumio[4001]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Sep 01 00:13:16 stefans-speaker volumio[4001]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Sep 01 00:13:16 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:13:16 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:13:16 stefans-speaker volumio[4001]: info: Starting MyVolumio Remote Streaming Endpoints Sep 01 00:13:16 stefans-speaker volumio[4001]: info: MyVolumio login type: Token Sep 01 00:13:16 stefans-speaker volumio[4001]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Sep 01 00:13:16 stefans-speaker volumio[4001]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Sep 01 00:13:17 stefans-speaker volumio[4001]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Sep 01 00:13:17 stefans-speaker volumio[4001]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Sep 01 00:13:17 stefans-speaker volumio[4001]: info: Streaming services startup Sep 01 00:13:17 stefans-speaker volumio[4001]: info: Starting Streaming Daemon Sep 01 00:13:17 stefans-speaker sudo[4338]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:13:17 stefans-speaker volumio[4001]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Sep 01 00:13:17 stefans-speaker sudo[4338]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Sep 01 00:13:17 stefans-speaker sudo[4338]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:13:17 stefans-speaker sudo[4338]: pam_unix(sudo:session): session closed for user root Sep 01 00:13:17 stefans-speaker volumio[4001]: info: Initializing connection to go-librespot Websocket Sep 01 00:13:17 stefans-speaker volumio[4001]: error: Cannot start Volumio Streaming Daemon Sep 01 00:13:17 stefans-speaker volumio[4001]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Sep 01 00:13:17 stefans-speaker volumio[4001]: sudo: unable to resolve host stefans-speaker: System error Sep 01 00:13:17 stefans-speaker volumio[4001]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Sep 01 00:13:17 stefans-speaker volumio[4001]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 00:13:18 stefans-speaker volumio[4001]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Sep 01 00:13:18 stefans-speaker volumio[4001]: info: MyVolumio token set successfully Sep 01 00:13:18 stefans-speaker volumio[4001]: info: MYVOLUMIO: Adding device Sep 01 00:13:18 stefans-speaker volumio[4001]: info: MYVOLUMIO: Evaluating Server Sep 01 00:13:19 stefans-speaker volumio[4001]: info: MyVolumio status changed Sep 01 00:13:19 stefans-speaker volumio[4001]: info: Streaming services startup Sep 01 00:13:19 stefans-speaker volumio[4001]: info: Starting Streaming Daemon Sep 01 00:13:19 stefans-speaker volumio[4001]: info: Removing browser output: myVolumio user plan is not superstar Sep 01 00:13:19 stefans-speaker volumio[4001]: info: Removing audio output: Sep 01 00:13:19 stefans-speaker volumio[4001]: info: Stoppping Tunnel 1 Sep 01 00:13:19 stefans-speaker sudo[4365]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:13:19 stefans-speaker sudo[4365]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Sep 01 00:13:19 stefans-speaker sudo[4365]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:13:19 stefans-speaker sudo[4367]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:13:19 stefans-speaker sudo[4367]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Sep 01 00:13:19 stefans-speaker sudo[4367]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:13:19 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Sep 01 00:13:19 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:13:19 stefans-speaker volumio[4001]: info: Setting Geolocation for MyVolumio to eu8 Sep 01 00:13:19 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:13:19 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:13:19 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:13:19 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:13:19 stefans-speaker go-librespot[4370]: go-librespot daemon starting... Sep 01 00:13:19 stefans-speaker sudo[4365]: pam_unix(sudo:session): session closed for user root Sep 01 00:13:19 stefans-speaker systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Sep 01 00:13:19 stefans-speaker systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Sep 01 00:13:19 stefans-speaker volumio[4001]: error: Cannot start Volumio Streaming Daemon Sep 01 00:13:19 stefans-speaker volumio[4001]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Sep 01 00:13:19 stefans-speaker volumio[4001]: sudo: unable to resolve host stefans-speaker: System error Sep 01 00:13:19 stefans-speaker volumio[4001]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Sep 01 00:13:19 stefans-speaker go-librespot[4371]: time="2026-09-01T00:13:19+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:13:19 stefans-speaker go-librespot[4371]: time="2026-09-01T00:13:19+02:00" level=debug msg="app state loaded" Sep 01 00:13:19 stefans-speaker go-librespot[4371]: time="2026-09-01T00:13:19+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:13:19 stefans-speaker systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Sep 01 00:13:19 stefans-speaker systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Sep 01 00:13:19 stefans-speaker systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Sep 01 00:13:19 stefans-speaker systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Sep 01 00:13:19 stefans-speaker systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Sep 01 00:13:19 stefans-speaker systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Sep 01 00:13:19 stefans-speaker sudo[4367]: pam_unix(sudo:session): session closed for user root Sep 01 00:13:19 stefans-speaker volumio[4001]: info: Remote SSH Stopped Sep 01 00:13:19 stefans-speaker go-librespot[4371]: time="2026-09-01T00:13:19+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 00:13:19 stefans-speaker go-librespot[4371]: time="2026-09-01T00:13:19+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 01 00:13:19 stefans-speaker go-librespot[4371]: time="2026-09-01T00:13:19+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 01 00:13:19 stefans-speaker go-librespot[4371]: time="2026-09-01T00:13:19+02:00" level=info msg="zeroconf server listening on port 44607" Sep 01 00:13:19 stefans-speaker volumio[4001]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Sep 01 00:13:19 stefans-speaker go-librespot[4371]: time="2026-09-01T00:13:19+02:00" level=debug msg="obtained new client token: AAEve61US+48HJ4A0GaL7x+APuL6+9K7fsY7IhyCFg1ABSUDSPtEtn1DZe67HO0pHAARcW5X7z5E679UaztJe/DSiS/URWEGDtIy6zHHUY8K+FIVbAFwSePboJD68Pml6UHICi/de1ZBZ4qd8G8haIpTAEeAFjnb7Y71qVv8MZpX5GHlfY4zw8O9wJQPy2/w1X1PCo1WivDAS4hApU1WgIyNXoD+AOuHSbJ1iW4OFIlrG0xil0Z43kyFmic=" Sep 01 00:13:19 stefans-speaker go-librespot[4371]: time="2026-09-01T00:13:19+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 00:13:20 stefans-speaker go-librespot[4371]: time="2026-09-01T00:13:20+02:00" level=debug msg="completed keyexchange" Sep 01 00:13:20 stefans-speaker go-librespot[4371]: time="2026-09-01T00:13:20+02:00" level=debug msg="completed challenge" Sep 01 00:13:20 stefans-speaker go-librespot[4371]: time="2026-09-01T00:13:20+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:13:20 stefans-speaker go-librespot[4371]: time="2026-09-01T00:13:20+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 00:13:20 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:13:20 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:13:20 stefans-speaker volumio[4001]: info: Updating MyVolumio device info Sep 01 00:13:20 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:13:20 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:13:20 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:13:20 stefans-speaker volumio[4001]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Sep 01 00:13:20 stefans-speaker volumio[4001]: info: Initializing connection to go-librespot Websocket Sep 01 00:13:20 stefans-speaker volumio[4001]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 00:13:23 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Sep 01 00:13:23 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:13:23 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:13:23 stefans-speaker go-librespot[4379]: go-librespot daemon starting... Sep 01 00:13:23 stefans-speaker go-librespot[4380]: time="2026-09-01T00:13:23+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:13:23 stefans-speaker go-librespot[4380]: time="2026-09-01T00:13:23+02:00" level=debug msg="app state loaded" Sep 01 00:13:23 stefans-speaker go-librespot[4380]: time="2026-09-01T00:13:23+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:13:23 stefans-speaker go-librespot[4380]: time="2026-09-01T00:13:23+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Sep 01 00:13:23 stefans-speaker go-librespot[4380]: time="2026-09-01T00:13:23+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Sep 01 00:13:23 stefans-speaker go-librespot[4380]: time="2026-09-01T00:13:23+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Sep 01 00:13:23 stefans-speaker go-librespot[4380]: time="2026-09-01T00:13:23+02:00" level=info msg="zeroconf server listening on port 39739" Sep 01 00:13:23 stefans-speaker go-librespot[4380]: time="2026-09-01T00:13:23+02:00" level=debug msg="obtained new client token: AAFMGyb6y3TTlNg17+LS51KMOZ8if6B34kIDwc2Cd4JUC30xHky4DYXNw3iyNkOwE6NAksWcDGYNRGpkOzAMWWoz+mSf/x2jmyw1vJ9tYiDrmGWJmtWhbEOpGloSXBDOq3z63IkbB0rM6tYupq8Gfm9QEg1iykTO6x8qRl9v3MrOvnxKmKwNwcDk7UyzEA05SqzcPhQ23jmHS6aVShQEyooNo9kWGPfXMpqOp9i3JqV49+iXfBYbe8g22pQ=" Sep 01 00:13:23 stefans-speaker go-librespot[4380]: time="2026-09-01T00:13:23+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 00:13:23 stefans-speaker go-librespot[4380]: time="2026-09-01T00:13:23+02:00" level=debug msg="completed keyexchange" Sep 01 00:13:23 stefans-speaker go-librespot[4380]: time="2026-09-01T00:13:23+02:00" level=debug msg="completed challenge" Sep 01 00:13:23 stefans-speaker volumio[4001]: info: MYVOLUMIO: Adding device Sep 01 00:13:23 stefans-speaker volumio[4001]: info: MYVOLUMIO: Evaluating Server Sep 01 00:13:23 stefans-speaker volumio[4001]: info: Initializing connection to go-librespot Websocket Sep 01 00:13:23 stefans-speaker go-librespot[4380]: time="2026-09-01T00:13:23+02:00" level=debug msg="new websocket client" Sep 01 00:13:23 stefans-speaker volumio[4001]: info: Connection to go-librespot Websocket established Sep 01 00:13:23 stefans-speaker go-librespot[4380]: time="2026-09-01T00:13:23+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:13:24 stefans-speaker go-librespot[4380]: time="2026-09-01T00:13:24+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 00:13:24 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:13:24 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:13:24 stefans-speaker volumio[4001]: info: Connection to go-librespot Websocket closed Sep 01 00:13:26 stefans-speaker volumio[4001]: info: Setting Geolocation for MyVolumio to eu5 Sep 01 00:13:26 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:13:26 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:13:26 stefans-speaker volumio[4001]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:13:26 stefans-speaker volumio[4001]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Sep 01 00:13:26 stefans-speaker volumio[4001]: info: Getting Spotify volume Sep 01 00:13:26 stefans-speaker volumio[4001]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 01 00:13:26 stefans-speaker volumio[4001]: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 00:13:26 stefans-speaker volumio[4001]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Sep 01 00:13:26 stefans-speaker volumio[4001]: errno: -111, Sep 01 00:13:26 stefans-speaker volumio[4001]: code: 'ECONNREFUSED', Sep 01 00:13:26 stefans-speaker volumio[4001]: syscall: 'connect', Sep 01 00:13:26 stefans-speaker volumio[4001]: address: '127.0.0.1', Sep 01 00:13:26 stefans-speaker volumio[4001]: port: 9879, Sep 01 00:13:26 stefans-speaker volumio[4001]: response: undefined Sep 01 00:13:26 stefans-speaker volumio[4001]: } Sep 01 00:13:26 stefans-speaker volumio[4001]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 01 00:13:27 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Sep 01 00:13:27 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:13:27 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:13:27 stefans-speaker go-librespot[4432]: go-librespot daemon starting... Sep 01 00:13:27 stefans-speaker go-librespot[4433]: time="2026-09-01T00:13:27+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:13:27 stefans-speaker go-librespot[4433]: time="2026-09-01T00:13:27+02:00" level=debug msg="app state loaded" Sep 01 00:13:27 stefans-speaker go-librespot[4433]: time="2026-09-01T00:13:27+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:13:27 stefans-speaker go-librespot[4433]: time="2026-09-01T00:13:27+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 00:13:27 stefans-speaker go-librespot[4433]: time="2026-09-01T00:13:27+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 01 00:13:27 stefans-speaker go-librespot[4433]: time="2026-09-01T00:13:27+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 01 00:13:27 stefans-speaker go-librespot[4433]: time="2026-09-01T00:13:27+02:00" level=info msg="zeroconf server listening on port 33319" Sep 01 00:13:27 stefans-speaker go-librespot[4433]: time="2026-09-01T00:13:27+02:00" level=debug msg="obtained new client token: AAFEnxQakmcWnewOXeXd//S7KeITPh/047ZT14VzmV1ezHCLOuf8c27fpTFiHCTrcqFrCA1PH6dlnY/U9Qt9B1SvsY7z27DB7A/HK/Y1ux3NbkX/3sXkz8h5erPe90WcMMgCoMsCd2aAjvvQvpE8NuqjG7KkLu4MfpsuA5n0sHkXiJogo3xIYMNFkA9By12iM8uqVmjLEVqEIgUnhEIZ2+G8VeapC3g2bHnOEF565jF0IRDKrCLk4D5sG1g=" Sep 01 00:13:27 stefans-speaker go-librespot[4433]: time="2026-09-01T00:13:27+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 00:13:27 stefans-speaker go-librespot[4433]: time="2026-09-01T00:13:27+02:00" level=debug msg="completed keyexchange" Sep 01 00:13:27 stefans-speaker go-librespot[4433]: time="2026-09-01T00:13:27+02:00" level=debug msg="completed challenge" Sep 01 00:13:27 stefans-speaker go-librespot[4433]: time="2026-09-01T00:13:27+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:13:27 stefans-speaker sudo[4443]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:13:27 stefans-speaker sudo[4443]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-09-01 00:12' Sep 01 00:13:27 stefans-speaker sudo[4443]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:13:27 stefans-speaker go-librespot[4433]: time="2026-09-01T00:13:27+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 00:13:27 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:13:27 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:13:27 stefans-speaker sudo[4443]: pam_unix(sudo:session): session closed for user root Sep 01 00:13:27 stefans-speaker volumio[4001]: sudo: unable to resolve host stefans-speaker: System error Sep 01 00:13:28 stefans-speaker volumio-remote-updater[679]: [2026-09-01 00:13:28] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Sep 01 00:13:28 stefans-speaker volumio-remote-updater[679]: [2026-09-01 00:13:28] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Sep 01 00:13:28 stefans-speaker systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:13:28 stefans-speaker systemd[1]: volumio.service: Failed with result 'exit-code'. Sep 01 00:13:28 stefans-speaker systemd[1]: volumio.service: Consumed 32.911s CPU time. Sep 01 00:13:28 stefans-speaker systemd[1]: Started dynamicswap.service - dynamicswap service. Sep 01 00:13:28 stefans-speaker systemd[1]: dynamicswap.service: Deactivated successfully. Sep 01 00:13:28 stefans-speaker systemd[1]: volumio.service: Scheduled restart job, restart counter is at 212. Sep 01 00:13:28 stefans-speaker systemd[1]: Started dynamicswap.service - dynamicswap service. Sep 01 00:13:28 stefans-speaker systemd[1]: Stopped volumio.service - Volumio Backend Module. Sep 01 00:13:28 stefans-speaker systemd[1]: volumio.service: Consumed 32.911s CPU time. Sep 01 00:13:28 stefans-speaker systemd[1]: Started volumio.service - Volumio Backend Module. Sep 01 00:13:28 stefans-speaker systemd[1]: dynamicswap.service: Deactivated successfully. Sep 01 00:13:30 stefans-speaker volumio[4457]: info: ------------------------------------------- Sep 01 00:13:30 stefans-speaker volumio[4457]: info: ----- Volumio3 ---- Sep 01 00:13:30 stefans-speaker volumio[4457]: info: ------------------------------------------- Sep 01 00:13:30 stefans-speaker volumio[4457]: info: ----- System startup ---- Sep 01 00:13:30 stefans-speaker volumio[4457]: info: ------------------------------------------- Sep 01 00:13:31 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Sep 01 00:13:31 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:13:31 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:13:31 stefans-speaker go-librespot[4481]: go-librespot daemon starting... Sep 01 00:13:31 stefans-speaker go-librespot[4482]: time="2026-09-01T00:13:31+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:13:31 stefans-speaker go-librespot[4482]: time="2026-09-01T00:13:31+02:00" level=debug msg="app state loaded" Sep 01 00:13:31 stefans-speaker go-librespot[4482]: time="2026-09-01T00:13:31+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:13:31 stefans-speaker volumio[4457]: info: MYVOLUMIO Environment detected Sep 01 00:13:31 stefans-speaker volumio[4457]: info: Plugin folders cleanup Sep 01 00:13:31 stefans-speaker volumio[4457]: info: Scanning into folder /volumio/app/plugins/ Sep 01 00:13:31 stefans-speaker volumio[4457]: info: Scanning category audio_interface Sep 01 00:13:31 stefans-speaker volumio[4457]: info: Scanning category miscellanea Sep 01 00:13:31 stefans-speaker volumio[4457]: info: Scanning category music_service Sep 01 00:13:31 stefans-speaker volumio[4457]: info: Scanning category plugins.json Sep 01 00:13:31 stefans-speaker volumio[4457]: info: Scanning category system_controller Sep 01 00:13:31 stefans-speaker volumio[4457]: info: Scanning category user_interface Sep 01 00:13:31 stefans-speaker volumio[4457]: info: Scanning into folder /data/plugins/ Sep 01 00:13:31 stefans-speaker volumio[4457]: info: Scanning category music_service Sep 01 00:13:31 stefans-speaker volumio[4457]: info: Plugin folders cleanup completed Sep 01 00:13:31 stefans-speaker volumio[4457]: info: ------------------------------------------- Sep 01 00:13:31 stefans-speaker volumio[4457]: info: ----- Core plugins startup ---- Sep 01 00:13:31 stefans-speaker volumio[4457]: info: ------------------------------------------- Sep 01 00:13:31 stefans-speaker volumio[4457]: info: Loading plugins from folder /volumio/app/plugins/ Sep 01 00:13:31 stefans-speaker volumio[4457]: info: Adding plugin upnp to MyMusic Plugins Sep 01 00:13:31 stefans-speaker volumio[4457]: info: Adding plugin airplay_emulation to MyMusic Plugins Sep 01 00:13:31 stefans-speaker volumio[4457]: info: Adding plugin upnp_browser to MyMusic Plugins Sep 01 00:13:31 stefans-speaker volumio[4457]: info: Loading plugins from folder /data/plugins/ Sep 01 00:13:31 stefans-speaker volumio[4457]: info: Loading plugin "system"... Sep 01 00:13:31 stefans-speaker volumio[4457]: info: Loading plugin "appearance"... Sep 01 00:13:31 stefans-speaker go-librespot[4482]: time="2026-09-01T00:13:31+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 00:13:31 stefans-speaker go-librespot[4482]: time="2026-09-01T00:13:31+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 01 00:13:31 stefans-speaker go-librespot[4482]: time="2026-09-01T00:13:31+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 01 00:13:31 stefans-speaker go-librespot[4482]: time="2026-09-01T00:13:31+02:00" level=info msg="zeroconf server listening on port 46017" Sep 01 00:13:31 stefans-speaker go-librespot[4482]: time="2026-09-01T00:13:31+02:00" level=debug msg="obtained new client token: AAG7lFb/LqPGaiYXk6GITpV4HO/dmMuc1oB4JLho25qKJx1chPXK+tci7B+yrrbY3CA31ZqhNufX6NbB1zDuawh/GrvxYwl53K2bxvWzWsBOKXuYm4k1sPTq/gUuKbeQhwMhh6kT6cxTFcdpRWLNLf8+E+98dDm+E35veuYnwwCR3n4+92eC/mLWZYA9gq3dQPbBNpcl+UVGQD9ghKEvRKwCGt8o6VHV0pRiPwtzXZrf0LgrQgPwdsRaqoQ=" Sep 01 00:13:31 stefans-speaker go-librespot[4482]: time="2026-09-01T00:13:31+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 00:13:31 stefans-speaker go-librespot[4482]: time="2026-09-01T00:13:31+02:00" level=debug msg="completed keyexchange" Sep 01 00:13:31 stefans-speaker go-librespot[4482]: time="2026-09-01T00:13:31+02:00" level=debug msg="completed challenge" Sep 01 00:13:31 stefans-speaker go-librespot[4482]: time="2026-09-01T00:13:31+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:13:31 stefans-speaker go-librespot[4482]: time="2026-09-01T00:13:31+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 00:13:31 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:13:31 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:13:32 stefans-speaker volumio[4457]: info: Loading plugin "network"... Sep 01 00:13:32 stefans-speaker volumio[4457]: info: Refreshing Cached IP Addresses Sep 01 00:13:32 stefans-speaker volumio[4457]: info: Loading plugin "services"... Sep 01 00:13:32 stefans-speaker sudo[4496]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:13:32 stefans-speaker sudo[4498]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:13:32 stefans-speaker volumio[4457]: info: Loading plugin "alsa_controller"... Sep 01 00:13:32 stefans-speaker sudo[4498]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 01 00:13:32 stefans-speaker sudo[4496]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 01 00:13:32 stefans-speaker sudo[4496]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:13:32 stefans-speaker sudo[4498]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:13:32 stefans-speaker sudo[4505]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:13:32 stefans-speaker sudo[4496]: pam_unix(sudo:session): session closed for user root Sep 01 00:13:32 stefans-speaker sudo[4498]: pam_unix(sudo:session): session closed for user root Sep 01 00:13:32 stefans-speaker sudo[4505]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Sep 01 00:13:32 stefans-speaker sudo[4505]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:13:32 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 01 00:13:32 stefans-speaker volumio[4457]: info: Loading plugin "wizard"... Sep 01 00:13:32 stefans-speaker volumio[4457]: info: Loading plugin "networkfs"... Sep 01 00:13:32 stefans-speaker volumio[4457]: info: Starting Udev Watcher for removable devices Sep 01 00:13:32 stefans-speaker volumio[4457]: info: Ignoring mount for partition: boot Sep 01 00:13:32 stefans-speaker volumio[4457]: info: Ignoring mount for partition: volumio Sep 01 00:13:32 stefans-speaker volumio[4457]: info: Ignoring mount for partition: volumio_data Sep 01 00:13:32 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 01 00:13:32 stefans-speaker volumio[4457]: info: Loading plugin "volumio_command_line_client"... Sep 01 00:13:32 stefans-speaker volumio[4457]: info: Loading plugin "upnp"... Sep 01 00:13:32 stefans-speaker volumio[4457]: info: [1788214412674] Starting Upmpd Daemon Sep 01 00:13:32 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 01 00:13:32 stefans-speaker volumio[4457]: info: Loading plugin "my_music"... Sep 01 00:13:32 stefans-speaker volumio[4457]: info: Loading plugin "mpd"... Sep 01 00:13:33 stefans-speaker volumio-remote-updater[679]: [2026-09-01 00:13:33] [connect] Successful connection Sep 01 00:13:33 stefans-speaker volumio[4457]: info: Loading plugin "upnp_browser"... Sep 01 00:13:34 stefans-speaker volumio[4457]: info: Starting UPNP Browser Sep 01 00:13:34 stefans-speaker volumio[4457]: info: Loading plugin "alarm-clock"... Sep 01 00:13:34 stefans-speaker volumio[4457]: info: Loading plugin "airplay_emulation"... Sep 01 00:13:34 stefans-speaker volumio[4457]: info: Starting Shairport Sync Sep 01 00:13:34 stefans-speaker volumio[4457]: info: Loading plugin "last_100"... Sep 01 00:13:34 stefans-speaker volumio[4457]: info: Loading plugin "webradio"... Sep 01 00:13:34 stefans-speaker volumio[4457]: info: Loading plugin "i2s_dacs"... Sep 01 00:13:34 stefans-speaker volumio[4457]: info: I2S DAC not set, start Auto-detection Sep 01 00:13:34 stefans-speaker volumio[4457]: info: Loading plugin "volumiodiscovery"... Sep 01 00:13:34 stefans-speaker volumio[4457]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 01 00:13:34 stefans-speaker volumio[4457]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 01 00:13:34 stefans-speaker volumio[4457]: *** WARNING *** For more information see Sep 01 00:13:34 stefans-speaker volumio[4457]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 01 00:13:34 stefans-speaker volumio[4457]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 01 00:13:34 stefans-speaker volumio[4457]: *** WARNING *** For more information see Sep 01 00:13:34 stefans-speaker node[4457]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 01 00:13:34 stefans-speaker node[4457]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 01 00:13:34 stefans-speaker node[4457]: *** WARNING *** For more information see Sep 01 00:13:34 stefans-speaker node[4457]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 01 00:13:34 stefans-speaker node[4457]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 01 00:13:34 stefans-speaker node[4457]: *** WARNING *** For more information see Sep 01 00:13:34 stefans-speaker volumio[4457]: info: Applying required configuration parameters for plugin volumiodiscovery Sep 01 00:13:34 stefans-speaker volumio[4457]: info: Discovery: Started advertising with name: Stefan’s Speaker Sep 01 00:13:35 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 01 00:13:35 stefans-speaker volumio[4457]: info: Loading plugin "spop"... Sep 01 00:13:35 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Sep 01 00:13:35 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:13:35 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:13:35 stefans-speaker go-librespot[4531]: go-librespot daemon starting... Sep 01 00:13:35 stefans-speaker go-librespot[4532]: time="2026-09-01T00:13:35+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:13:35 stefans-speaker go-librespot[4532]: time="2026-09-01T00:13:35+02:00" level=debug msg="app state loaded" Sep 01 00:13:35 stefans-speaker go-librespot[4532]: time="2026-09-01T00:13:35+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:13:35 stefans-speaker go-librespot[4532]: time="2026-09-01T00:13:35+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 00:13:35 stefans-speaker go-librespot[4532]: time="2026-09-01T00:13:35+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 01 00:13:35 stefans-speaker go-librespot[4532]: time="2026-09-01T00:13:35+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 01 00:13:35 stefans-speaker go-librespot[4532]: time="2026-09-01T00:13:35+02:00" level=info msg="zeroconf server listening on port 43555" Sep 01 00:13:35 stefans-speaker sudo[4505]: pam_unix(sudo:session): session closed for user root Sep 01 00:13:35 stefans-speaker go-librespot[4532]: time="2026-09-01T00:13:35+02:00" level=debug msg="obtained new client token: AAFkATsTnMhqF3lzW92Ks4jzDGZg1EaeTYRYO583n3aPFRmpxblM2r+tTfqC/v8Bqp2sVcSFSC+inw0uuEx3Km64AfC98zsPCBa+4L7bGhDoy8JU8nOOpPOmKpcxkSNdLBn+w2Z/4v7KCeLqtYg2pkWwKBKN5NyAX5TU5wLpofowQyg0LolhC4e8eEb7g3rCp15L7O5goIlxKOIsd3m4xtUg3YkfLRYqfPXAoyrFe2DygW7uiYGBcVxYTos=" Sep 01 00:13:35 stefans-speaker go-librespot[4532]: time="2026-09-01T00:13:35+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 00:13:35 stefans-speaker go-librespot[4532]: time="2026-09-01T00:13:35+02:00" level=debug msg="completed keyexchange" Sep 01 00:13:35 stefans-speaker go-librespot[4532]: time="2026-09-01T00:13:35+02:00" level=debug msg="completed challenge" Sep 01 00:13:36 stefans-speaker go-librespot[4532]: time="2026-09-01T00:13:36+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:13:36 stefans-speaker volumio[4457]: info: Loading plugin "ytcr"... Sep 01 00:13:36 stefans-speaker go-librespot[4532]: time="2026-09-01T00:13:36+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 00:13:36 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:13:36 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:13:37 stefans-speaker volumio[4457]: info: Loading plugin "outputs"... Sep 01 00:13:37 stefans-speaker volumio[4457]: info: Loading plugin "albumart"... Sep 01 00:13:37 stefans-speaker volumio[4457]: info: Plugin example_plugin is not enabled Sep 01 00:13:37 stefans-speaker volumio[4457]: info: Loading plugin "inputs"... Sep 01 00:13:37 stefans-speaker volumio[4457]: info: Loading plugin "updater_comm"... Sep 01 00:13:37 stefans-speaker volumio[4457]: info: Plugin mpdemulation is not enabled Sep 01 00:13:37 stefans-speaker volumio[4457]: info: Loading plugin "rest_api"... Sep 01 00:13:37 stefans-speaker volumio[4457]: info: Loading plugin "websocket"... Sep 01 00:13:37 stefans-speaker volumio[4457]: info: Starting Socket.io Server version 1.7.4 Sep 01 00:13:37 stefans-speaker volumio[4457]: info: Loading i18n strings for locale nl Sep 01 00:13:37 stefans-speaker volumio[4457]: Updating browse sources language Sep 01 00:13:37 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 00:13:37 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 00:13:37 stefans-speaker volumio[4457]: info: CoreCommandRouter::initPlayerControls Sep 01 00:13:37 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:37 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:37 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:37 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:37 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:37 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:37 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:37 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:37 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 00:13:37 stefans-speaker volumio[4457]: Express server listening on port 3000 Sep 01 00:13:37 stefans-speaker volumio[4457]: [Metrics] WebUI: 8s 148.92ms Sep 01 00:13:38 stefans-speaker volumio[4457]: info: CoreStateMachine::resetVolumioState Sep 01 00:13:38 stefans-speaker volumio[4457]: info: CoreStateMachine::getcurrentVolume Sep 01 00:13:38 stefans-speaker volumio[4457]: info: CoreCommandRouter::volumioRetrievevolume Sep 01 00:13:38 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:13:38 stefans-speaker volumio[4457]: info: Cannot read play queue from file Sep 01 00:13:38 stefans-speaker volumio[4457]: info: Volumio Network Manager: Network status updated: 2 Sep 01 00:13:38 stefans-speaker volumio[4541]: Forking 3 albumart workers Sep 01 00:13:38 stefans-speaker volumio[4457]: info: VolumeController:: Volume=70 Mute =false Sep 01 00:13:38 stefans-speaker volumio[4457]: info: CoreStateMachine::pushState Sep 01 00:13:38 stefans-speaker volumio[4457]: info: CorePlayQueue::getTrack 0 Sep 01 00:13:38 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 01 00:13:38 stefans-speaker volumio[4457]: info: CoreCommandRouter::volumioPushState Sep 01 00:13:38 stefans-speaker volumio[4457]: info: CoreStateMachine::updateTrackBlock Sep 01 00:13:38 stefans-speaker volumio[4457]: info: CorePlayQueue::getTrackBlock Sep 01 00:13:38 stefans-speaker volumio[4457]: info: CoreCommandRouter::volumioRetrievevolume Sep 01 00:13:38 stefans-speaker volumio[4457]: info: CoreStateMachine::setRepeat null single undefined Sep 01 00:13:38 stefans-speaker volumio[4457]: info: CoreStateMachine::pushState Sep 01 00:13:38 stefans-speaker volumio[4457]: info: CorePlayQueue::getTrack 0 Sep 01 00:13:38 stefans-speaker volumio[4457]: info: CoreCommandRouter::volumioPushState Sep 01 00:13:38 stefans-speaker volumio[4457]: info: CoreStateMachine::setRandom null Sep 01 00:13:38 stefans-speaker volumio[4457]: info: CoreStateMachine::pushState Sep 01 00:13:38 stefans-speaker volumio[4457]: info: CorePlayQueue::getTrack 0 Sep 01 00:13:38 stefans-speaker volumio[4457]: info: CoreCommandRouter::volumioPushState Sep 01 00:13:38 stefans-speaker volumio[4457]: info: Setting Device type: Raspberry PI Sep 01 00:13:38 stefans-speaker volumio[4457]: info: VolumeController:: Volume=70 Mute =false Sep 01 00:13:38 stefans-speaker volumio[4457]: info: CoreStateMachine::pushState Sep 01 00:13:38 stefans-speaker volumio[4457]: info: CorePlayQueue::getTrack 0 Sep 01 00:13:38 stefans-speaker volumio[4457]: info: CoreCommandRouter::volumioPushState Sep 01 00:13:38 stefans-speaker volumio[4457]: info: Discovery: adding a312d0fa-c0eb-45ad-a25b-79fcdf237e8a Sep 01 00:13:38 stefans-speaker volumio[4457]: info: Discovery: Found device Stefan’s Speaker Sep 01 00:13:38 stefans-speaker volumio[4457]: info: CoreCommandRouter::volumioGetState Sep 01 00:13:38 stefans-speaker volumio[4457]: info: CorePlayQueue::getTrack 0 Sep 01 00:13:38 stefans-speaker volumio[4457]: info: Discovery: this is already registered, a312d0fa-c0eb-45ad-a25b-79fcdf237e8a Sep 01 00:13:38 stefans-speaker volumio[4457]: info: Discovery: Found device Stefan’s Speaker Sep 01 00:13:38 stefans-speaker volumio[4457]: info: CoreCommandRouter::volumioGetState Sep 01 00:13:38 stefans-speaker volumio[4457]: info: CorePlayQueue::getTrack 0 Sep 01 00:13:38 stefans-speaker volumio[4457]: info: Completed loading Core Plugins Sep 01 00:13:38 stefans-speaker volumio[4457]: info: Preparing to generate the ALSA configuration file Sep 01 00:13:38 stefans-speaker volumio[4457]: info: Asound.conf file unchanged, so no further update is needed Sep 01 00:13:38 stefans-speaker volumio[4457]: info: Output device has changed, restarting MPD Sep 01 00:13:38 stefans-speaker volumio[4457]: info: Output device has changed, restarting Shairport Sync Sep 01 00:13:38 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:38 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:13:38 stefans-speaker sudo[4596]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:13:38 stefans-speaker sudo[4597]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:13:38 stefans-speaker sudo[4596]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 01 00:13:38 stefans-speaker sudo[4596]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:13:38 stefans-speaker sudo[4597]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 01 00:13:38 stefans-speaker sudo[4597]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:13:38 stefans-speaker volumio[4457]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 01 00:13:38 stefans-speaker volumio[4457]: info: ___________ START PLUGINS ___________ Sep 01 00:13:38 stefans-speaker volumio[4457]: info: ControllerMpd::onStart: Initializing MPD Sep 01 00:13:38 stefans-speaker volumio[4457]: info: Creating MPD Configuration file Sep 01 00:13:38 stefans-speaker sudo[4596]: pam_unix(sudo:session): session closed for user root Sep 01 00:13:38 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 00:13:38 stefans-speaker volumio[4457]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 01 00:13:38 stefans-speaker volumio[4457]: info: [1788214418821] CoreMusicLibrary::Adding element Media Servers Sep 01 00:13:38 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 00:13:38 stefans-speaker volumio[4457]: info: UPNP Browser: Client initialized successfully Sep 01 00:13:38 stefans-speaker systemd[1]: Stopping mpd.service - Music Player Daemon... Sep 01 00:13:38 stefans-speaker sudo[4605]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:13:38 stefans-speaker sudo[4607]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:13:38 stefans-speaker sudo[4605]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 01 00:13:38 stefans-speaker sudo[4605]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:13:38 stefans-speaker systemd[1]: mpd.service: Deactivated successfully. Sep 01 00:13:38 stefans-speaker systemd[1]: Stopped mpd.service - Music Player Daemon. Sep 01 00:13:38 stefans-speaker systemd[1]: mpd.service: Consumed 4.476s CPU time. Sep 01 00:13:38 stefans-speaker systemd[1]: mpd.socket: Deactivated successfully. Sep 01 00:13:38 stefans-speaker sudo[4607]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 01 00:13:38 stefans-speaker sudo[4607]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:13:38 stefans-speaker systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Sep 01 00:13:38 stefans-speaker systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Sep 01 00:13:38 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:38 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:13:38 stefans-speaker sudo[4605]: pam_unix(sudo:session): session closed for user root Sep 01 00:13:38 stefans-speaker volumio[4457]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 01 00:13:39 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:39 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:13:39 stefans-speaker systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Sep 01 00:13:39 stefans-speaker systemd[1]: Starting mpd.service - Music Player Daemon... Sep 01 00:13:39 stefans-speaker volumio[4457]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 01 00:13:39 stefans-speaker systemd[1]: mpd.service: Deactivated successfully. Sep 01 00:13:39 stefans-speaker volumio[4457]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 01 00:13:39 stefans-speaker volumio[4457]: info: [1788214419075] CoreMusicLibrary::Adding element Last_100 Sep 01 00:13:39 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 00:13:39 stefans-speaker systemd[1]: Stopped mpd.service - Music Player Daemon. Sep 01 00:13:39 stefans-speaker systemd[1]: mpd.socket: Deactivated successfully. Sep 01 00:13:39 stefans-speaker systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Sep 01 00:13:39 stefans-speaker systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Sep 01 00:13:39 stefans-speaker volumio[4457]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 01 00:13:39 stefans-speaker volumio[4457]: info: [1788214419098] CoreMusicLibrary::Adding element Webradio Sep 01 00:13:39 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 00:13:39 stefans-speaker systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Sep 01 00:13:39 stefans-speaker systemd[1]: Starting mpd.service - Music Player Daemon... Sep 01 00:13:39 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 01 00:13:39 stefans-speaker volumio[4457]: info: Initializing BBC Radios Sep 01 00:13:39 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 01 00:13:39 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:13:39 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Sep 01 00:13:39 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:13:39 stefans-speaker volumio[4457]: info: Creating Spotify config file Sep 01 00:13:39 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:39 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:13:39 stefans-speaker go-librespot[4635]: go-librespot daemon starting... Sep 01 00:13:39 stefans-speaker sudo[4621]: root : unable to resolve host stefans-speaker: System error Sep 01 00:13:39 stefans-speaker sudo[4621]: sudo: unable to resolve host stefans-speaker: System error Sep 01 00:13:39 stefans-speaker go-librespot[4636]: time="2026-09-01T00:13:39+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:13:39 stefans-speaker sudo[4621]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Sep 01 00:13:39 stefans-speaker sudo[4621]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Sep 01 00:13:39 stefans-speaker sudo[4621]: pam_unix(sudo:session): session closed for user root Sep 01 00:13:39 stefans-speaker go-librespot[4636]: time="2026-09-01T00:13:39+02:00" level=info msg="zeroconf server listening on port 39889" Sep 01 00:13:40 stefans-speaker volumio[4557]: Starting albumart workers Sep 01 00:13:40 stefans-speaker volumio[4457]: info: Volumio Calling Home Sep 01 00:13:40 stefans-speaker volumio[4558]: Starting albumart workers Sep 01 00:13:40 stefans-speaker volumio[4556]: Starting albumart workers Sep 01 00:13:40 stefans-speaker volumio[4457]: info: MPD Permissions set Sep 01 00:13:40 stefans-speaker volumio[4457]: info: MPD Permissions set Sep 01 00:13:40 stefans-speaker volumio[4457]: info: Spotify config file written Sep 01 00:13:40 stefans-speaker volumio[4457]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Sep 01 00:13:40 stefans-speaker sudo[4651]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:13:40 stefans-speaker volumio[4457]: info: Volumio called home Sep 01 00:13:40 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:40 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:40 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:40 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:40 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:40 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:40 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:40 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:40 stefans-speaker sudo[4651]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Sep 01 00:13:40 stefans-speaker sudo[4651]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:13:40 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:13:40 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:40 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:40 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:40 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:40 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:40 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:40 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:40 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:40 stefans-speaker systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Sep 01 00:13:40 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:40 stefans-speaker systemd[1]: go-librespot-daemon.service: Deactivated successfully. Sep 01 00:13:40 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:13:41 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:13:41 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:13:41 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:13:41 stefans-speaker go-librespot[4660]: go-librespot daemon starting... Sep 01 00:13:41 stefans-speaker sudo[4651]: pam_unix(sudo:session): session closed for user root Sep 01 00:13:41 stefans-speaker volumio[4457]: info: No need to fix Spotify hosts Sep 01 00:13:41 stefans-speaker go-librespot[4665]: time="2026-09-01T00:13:41+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:13:41 stefans-speaker go-librespot[4665]: time="2026-09-01T00:13:41+02:00" level=debug msg="app state loaded" Sep 01 00:13:41 stefans-speaker go-librespot[4665]: time="2026-09-01T00:13:41+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:13:41 stefans-speaker go-librespot[4665]: time="2026-09-01T00:13:41+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 00:13:41 stefans-speaker go-librespot[4665]: time="2026-09-01T00:13:41+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 01 00:13:41 stefans-speaker go-librespot[4665]: time="2026-09-01T00:13:41+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 01 00:13:41 stefans-speaker go-librespot[4665]: time="2026-09-01T00:13:41+02:00" level=info msg="zeroconf server listening on port 40093" Sep 01 00:13:41 stefans-speaker go-librespot[4665]: time="2026-09-01T00:13:41+02:00" level=debug msg="obtained new client token: AAFRRvqFZIyZ7oquzFTlAgjZg2mEDH4jhKOi56R6Ja6gDkBcrQbMrtDjXIus7kMyGkgCjrJYPVDZc5QGe30lqrGcPJGubL7UyneScpzbpHc7phpZvSmxxHtsFwEJWFyS7H7wxVmKojS7qvWP9IACzsyIOyn6aMEO7tcYwLGlIlUyJvV4t0pUrA7QO/6Hgr6qvTS8ddZsak84OOCnLDcpNmAXRqH+wNKd2lHLwGCDbFOXsPnJCtGhapN+2ZA=" Sep 01 00:13:41 stefans-speaker go-librespot[4665]: time="2026-09-01T00:13:41+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 00:13:41 stefans-speaker go-librespot[4665]: time="2026-09-01T00:13:41+02:00" level=debug msg="completed keyexchange" Sep 01 00:13:41 stefans-speaker go-librespot[4665]: time="2026-09-01T00:13:41+02:00" level=debug msg="completed challenge" Sep 01 00:13:41 stefans-speaker go-librespot[4665]: time="2026-09-01T00:13:41+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:13:41 stefans-speaker volumio[4457]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Sep 01 00:13:41 stefans-speaker volumio[4457]: SPOTIFY: BQC82xRBpCDoINts8T7Xzbstqk1FTN8RM03or-ME5s7oU25kWiJ47LEYE-wdYnr6llsfgXO7nWWPzfgTusOnfWfkx3Hl_li-Kl1D77P-N_IV3VVmZSddVorurr7hMbJKn99kZShbPo-WFexy78BOZIA5MOvY-7BeSWfcPNS7niYRKsl0dIf3_pqlp95mGR9yYwpk3HA_QmvWcL35rmysnq_jGgr5RjTDU9F7t9ke601WyCznTy7uNlJxBaXKaVxPOUAJm-jKQ0SzaDXk70_XWUt4w11AHf_2Im8FZTjB6G9t9bfFLjxv9vfnP0yRq9w Sep 01 00:13:41 stefans-speaker volumio[4457]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Sep 01 00:13:41 stefans-speaker volumio[4457]: info: New Spotify access token = BQC82xRBpCDoINts8T7Xzbstqk1FTN8RM03or-ME5s7oU25kWiJ47LEYE-wdYnr6llsfgXO7nWWPzfgTusOnfWfkx3Hl_li-Kl1D77P-N_IV3VVmZSddVorurr7hMbJKn99kZShbPo-WFexy78BOZIA5MOvY-7BeSWfcPNS7niYRKsl0dIf3_pqlp95mGR9yYwpk3HA_QmvWcL35rmysnq_jGgr5RjTDU9F7t9ke601WyCznTy7uNlJxBaXKaVxPOUAJm-jKQ0SzaDXk70_XWUt4w11AHf_2Im8FZTjB6G9t9bfFLjxv9vfnP0yRq9w Sep 01 00:13:41 stefans-speaker volumio[4457]: info: Spotify credentials grant success - running version from March 24, 2019 Sep 01 00:13:41 stefans-speaker volumio[4457]: info: Starting Shairport Sync Sep 01 00:13:41 stefans-speaker volumio[4457]: info: Starting Shairport Sync Sep 01 00:13:41 stefans-speaker go-librespot[4665]: time="2026-09-01T00:13:41+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 00:13:41 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:13:41 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:13:41 stefans-speaker volumio[4457]: info: Starting Shairport Sync Sep 01 00:13:41 stefans-speaker sudo[4691]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:13:42 stefans-speaker sudo[4693]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:13:42 stefans-speaker sudo[4691]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 01 00:13:42 stefans-speaker sudo[4695]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:13:42 stefans-speaker sudo[4693]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 01 00:13:42 stefans-speaker sudo[4693]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:13:42 stefans-speaker sudo[4691]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:13:42 stefans-speaker sudo[4695]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 01 00:13:42 stefans-speaker sudo[4695]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:13:42 stefans-speaker volumio[4457]: info: CoreCommandRouter::volumioGetState Sep 01 00:13:42 stefans-speaker volumio[4457]: info: CorePlayQueue::getTrack 0 Sep 01 00:13:42 stefans-speaker systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Sep 01 00:13:42 stefans-speaker systemd[1]: shairport-sync.service: Deactivated successfully. Sep 01 00:13:42 stefans-speaker systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Sep 01 00:13:42 stefans-speaker systemd[1]: shairport-sync.service: Consumed 1.890s CPU time. Sep 01 00:13:42 stefans-speaker volumio[4457]: SPOTIFY: User informations: {"account_id":"zltuAJDW9c","country":"RO","display_name":"emanueluss","email":"emanuel.grecescu@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31mmtxvuufe76qdkk6caepwk3fcy"},"followers":{"href":null,"total":3},"href":"https://api.spotify.com/v1/users/31mmtxvuufe76qdkk6caepwk3fcy","id":"31mmtxvuufe76qdkk6caepwk3fcy","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee852e7ddfcb02af85c1462f3412","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b822e7ddfcb02af85c1462f3412","width":64}],"product":"premium","type":"user","uri":"spotify:user:31mmtxvuufe76qdkk6caepwk3fcy"} Sep 01 00:13:42 stefans-speaker volumio[4457]: info: Spotify Successfully logged in Sep 01 00:13:42 stefans-speaker volumio[4457]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 01 00:13:42 stefans-speaker volumio[4457]: info: [1788214422274] CoreMusicLibrary::Adding element Spotify Sep 01 00:13:42 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 00:13:42 stefans-speaker volumio[4457]: Cannot find translation for source Spotify Sep 01 00:13:42 stefans-speaker systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Sep 01 00:13:42 stefans-speaker sudo[4695]: pam_unix(sudo:session): session closed for user root Sep 01 00:13:42 stefans-speaker sudo[4691]: pam_unix(sudo:session): session closed for user root Sep 01 00:13:42 stefans-speaker sudo[4693]: pam_unix(sudo:session): session closed for user root Sep 01 00:13:42 stefans-speaker volumio[4457]: info: Shairport-Sync Started Sep 01 00:13:42 stefans-speaker volumio[4457]: Error adding Membership: Error: addMembership EINVAL Sep 01 00:13:42 stefans-speaker volumio[4457]: info: Shairport-Sync Started Sep 01 00:13:42 stefans-speaker volumio[4457]: info: Shairport-Sync Started Sep 01 00:13:42 stefans-speaker volumio[4457]: info: [yt-cast-receiver] DIAL server listening on port 8098 Sep 01 00:13:42 stefans-speaker volumio[4457]: info: CoreCommandRouter::volumioRetrievevolume Sep 01 00:13:42 stefans-speaker sudo[4730]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:13:42 stefans-speaker volumio[4457]: info: VolumeController:: Volume=70 Mute =false Sep 01 00:13:42 stefans-speaker volumio[4457]: info: CoreCommandRouter::volumioGetState Sep 01 00:13:42 stefans-speaker volumio[4457]: info: CorePlayQueue::getTrack 0 Sep 01 00:13:42 stefans-speaker volumio[4457]: info: CoreStateMachine::pushState Sep 01 00:13:42 stefans-speaker volumio[4457]: info: CorePlayQueue::getTrack 0 Sep 01 00:13:42 stefans-speaker volumio[4457]: info: CoreCommandRouter::volumioPushState Sep 01 00:13:42 stefans-speaker sudo[4730]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 01 00:13:42 stefans-speaker sudo[4730]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:13:42 stefans-speaker sudo[4732]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:13:42 stefans-speaker sudo[4732]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 01 00:13:42 stefans-speaker sudo[4730]: pam_unix(sudo:session): session closed for user root Sep 01 00:13:42 stefans-speaker sudo[4732]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:13:42 stefans-speaker sudo[4732]: pam_unix(sudo:session): session closed for user root Sep 01 00:13:42 stefans-speaker sudo[4737]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:13:42 stefans-speaker sudo[4737]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Sep 01 00:13:42 stefans-speaker sudo[4737]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:13:42 stefans-speaker sudo[4737]: pam_unix(sudo:session): session closed for user root Sep 01 00:13:42 stefans-speaker volumio[4457]: info: Upmpdcli Daemon Started Sep 01 00:13:43 stefans-speaker mpd[4644]: 2026-09-01T00:13:43 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Sep 01 00:13:43 stefans-speaker systemd[1]: Started mpd.service - Music Player Daemon. Sep 01 00:13:43 stefans-speaker sudo[4607]: pam_unix(sudo:session): session closed for user root Sep 01 00:13:43 stefans-speaker sudo[4597]: pam_unix(sudo:session): session closed for user root Sep 01 00:13:44 stefans-speaker volumio[4457]: error: MPD error: The expression evaluated to a falsy value: Sep 01 00:13:44 stefans-speaker volumio[4457]: assert.ok(self.idling) Sep 01 00:13:44 stefans-speaker volumio[4457]: error: The expression evaluated to a falsy value: Sep 01 00:13:44 stefans-speaker volumio[4457]: assert.ok(self.idling) Sep 01 00:13:44 stefans-speaker volumio[4457]: info: MPD running with PID4644 Sep 01 00:13:44 stefans-speaker volumio[4457]: ,establishing connection Sep 01 00:13:44 stefans-speaker volumio[4457]: error: updateQueue error: null Sep 01 00:13:44 stefans-speaker volumio[4457]: info: Completed starting Core Plugins Sep 01 00:13:44 stefans-speaker volumio[4457]: info: ------------------------------------------- Sep 01 00:13:44 stefans-speaker volumio[4457]: info: ----- MyVolumio plugins startup ---- Sep 01 00:13:44 stefans-speaker volumio[4457]: info: ------------------------------------------- Sep 01 00:13:44 stefans-speaker volumio[4457]: info: [MyVolumio PluginManager] Fetching plans data.... Sep 01 00:13:44 stefans-speaker volumio[4457]: error: updateQueue error: null Sep 01 00:13:44 stefans-speaker volumio[4457]: info: go-librespot daemon successfully initialized Sep 01 00:13:45 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Sep 01 00:13:45 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:13:45 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:13:45 stefans-speaker go-librespot[4745]: go-librespot daemon starting... Sep 01 00:13:45 stefans-speaker go-librespot[4746]: time="2026-09-01T00:13:45+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:13:45 stefans-speaker go-librespot[4746]: time="2026-09-01T00:13:45+02:00" level=debug msg="app state loaded" Sep 01 00:13:45 stefans-speaker go-librespot[4746]: time="2026-09-01T00:13:45+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:13:45 stefans-speaker go-librespot[4746]: time="2026-09-01T00:13:45+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 00:13:45 stefans-speaker go-librespot[4746]: time="2026-09-01T00:13:45+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 01 00:13:45 stefans-speaker go-librespot[4746]: time="2026-09-01T00:13:45+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 01 00:13:45 stefans-speaker go-librespot[4746]: time="2026-09-01T00:13:45+02:00" level=info msg="zeroconf server listening on port 39477" Sep 01 00:13:45 stefans-speaker go-librespot[4746]: time="2026-09-01T00:13:45+02:00" level=debug msg="obtained new client token: AAEjK2bapSDsHrkD2Xdd5JP8PtgR9VTpLS0kCRElceawj1I7a55UBK0Yy6VS2j+37DU8b8LMOCMh2zWrhZfIH3iwQB9qH6x3FOWoXAZoZzPT12pFHFDCSQ/EM8hw9Wi9FXNvLdr/QaRO6EKXnU9cg72gxC/k0aEvn2kQaC+ost1XpdZwrE7MxLd3C8w/47QnuBmXIcIfJHIaA1OejWbT+e1GBqRSjFVe7M6ymXuhWtntltuFW1iVblw40Es=" Sep 01 00:13:45 stefans-speaker volumio-remote-updater[679]: [2026-09-01 00:13:45] [connect] Successful connection Sep 01 00:13:45 stefans-speaker volumio-remote-updater[679]: [2026-09-01 00:13:45] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1788214425 101 Sep 01 00:13:45 stefans-speaker go-librespot[4746]: time="2026-09-01T00:13:45+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 00:13:45 stefans-speaker volumio[4457]: 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: 2 Sep 01 00:13:45 stefans-speaker go-librespot[4746]: time="2026-09-01T00:13:45+02:00" level=debug msg="completed keyexchange" Sep 01 00:13:45 stefans-speaker go-librespot[4746]: time="2026-09-01T00:13:45+02:00" level=debug msg="completed challenge" Sep 01 00:13:45 stefans-speaker go-librespot[4746]: time="2026-09-01T00:13:45+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:13:45 stefans-speaker go-librespot[4746]: time="2026-09-01T00:13:45+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 00:13:45 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:13:45 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:13:46 stefans-speaker sudo[4756]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:13:46 stefans-speaker sudo[4756]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Sep 01 00:13:46 stefans-speaker sudo[4756]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:13:46 stefans-speaker sudo[4758]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:13:46 stefans-speaker sudo[4758]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Sep 01 00:13:46 stefans-speaker sudo[4758]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:13:47 stefans-speaker systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Sep 01 00:13:47 stefans-speaker systemd[1]: mpd_monitor.service: Deactivated successfully. Sep 01 00:13:47 stefans-speaker systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Sep 01 00:13:47 stefans-speaker systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Sep 01 00:13:47 stefans-speaker mpd_monitor.sh[4761]: MPD Monitor Service: Starting MPD Monitor Service Sep 01 00:13:47 stefans-speaker sudo[4756]: pam_unix(sudo:session): session closed for user root Sep 01 00:13:47 stefans-speaker sudo[4758]: pam_unix(sudo:session): session closed for user root Sep 01 00:13:47 stefans-speaker volumio[4457]: info: Successfully started MPD Monitor Sep 01 00:13:47 stefans-speaker volumio[4457]: info: Successfully started MPD Monitor Sep 01 00:13:47 stefans-speaker volumio[4457]: info: Initializing connection to go-librespot Websocket Sep 01 00:13:47 stefans-speaker volumio[4457]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 00:13:48 stefans-speaker volumio[4457]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Sep 01 00:13:49 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Sep 01 00:13:49 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:13:49 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:13:49 stefans-speaker go-librespot[4765]: go-librespot daemon starting... Sep 01 00:13:49 stefans-speaker go-librespot[4766]: time="2026-09-01T00:13:49+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:13:49 stefans-speaker go-librespot[4766]: time="2026-09-01T00:13:49+02:00" level=debug msg="app state loaded" Sep 01 00:13:49 stefans-speaker go-librespot[4766]: time="2026-09-01T00:13:49+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:13:49 stefans-speaker go-librespot[4766]: time="2026-09-01T00:13:49+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 00:13:49 stefans-speaker go-librespot[4766]: time="2026-09-01T00:13:49+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 01 00:13:49 stefans-speaker go-librespot[4766]: time="2026-09-01T00:13:49+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 01 00:13:49 stefans-speaker go-librespot[4766]: time="2026-09-01T00:13:49+02:00" level=info msg="zeroconf server listening on port 43123" Sep 01 00:13:49 stefans-speaker go-librespot[4766]: time="2026-09-01T00:13:49+02:00" level=debug msg="obtained new client token: AAEPOXGrepYS0ZMjzCccIsjKTx4wi8sLL1XwKrg3PchlQRDyatFm/3x/GdPyh8rZQXxwFnDlIlVcCT4AD2HIb09bTHFZc6bNVx68BvJlqGTWntaHGKTIOX9vMbv5pv+HaIfh6DrzZDyFeUA3+5KT4FgsHScvOpOrlxwDH51eoJbmVJ1uVRq5yIGCuzDB1ZI1L3x3om3T5IMxsY8K4XOmSGpaZ76NMgAEFI8JiNxT4CfzosP9bI58Y8dpS/M=" Sep 01 00:13:49 stefans-speaker go-librespot[4766]: time="2026-09-01T00:13:49+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 00:13:49 stefans-speaker go-librespot[4766]: time="2026-09-01T00:13:49+02:00" level=debug msg="completed keyexchange" Sep 01 00:13:49 stefans-speaker go-librespot[4766]: time="2026-09-01T00:13:49+02:00" level=debug msg="completed challenge" Sep 01 00:13:49 stefans-speaker go-librespot[4766]: time="2026-09-01T00:13:49+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:13:49 stefans-speaker go-librespot[4766]: time="2026-09-01T00:13:49+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 00:13:49 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:13:49 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:13:50 stefans-speaker volumio[4457]: info: Initializing connection to go-librespot Websocket Sep 01 00:13:50 stefans-speaker volumio[4457]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 00:13:52 stefans-speaker volumio[4457]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Sep 01 00:13:52 stefans-speaker volumio[4457]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Sep 01 00:13:52 stefans-speaker volumio[4457]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Sep 01 00:13:52 stefans-speaker volumio[4457]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Sep 01 00:13:52 stefans-speaker volumio[4457]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Sep 01 00:13:52 stefans-speaker volumio[4457]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Sep 01 00:13:52 stefans-speaker volumio[4457]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Sep 01 00:13:52 stefans-speaker volumio[4457]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Sep 01 00:13:52 stefans-speaker volumio[4457]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Sep 01 00:13:52 stefans-speaker volumio[4457]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Sep 01 00:13:52 stefans-speaker volumio[4457]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Sep 01 00:13:52 stefans-speaker volumio[4457]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Sep 01 00:13:52 stefans-speaker volumio[4457]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Sep 01 00:13:52 stefans-speaker volumio[4457]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Sep 01 00:13:52 stefans-speaker volumio[4457]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Sep 01 00:13:52 stefans-speaker volumio[4457]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Sep 01 00:13:52 stefans-speaker volumio[4457]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Sep 01 00:13:52 stefans-speaker volumio[4457]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Sep 01 00:13:52 stefans-speaker volumio[4457]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Sep 01 00:13:52 stefans-speaker volumio[4457]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Sep 01 00:13:52 stefans-speaker volumio[4457]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Sep 01 00:13:52 stefans-speaker volumio[4457]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Sep 01 00:13:52 stefans-speaker volumio[4457]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Sep 01 00:13:52 stefans-speaker volumio[4457]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Sep 01 00:13:52 stefans-speaker volumio[4457]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Sep 01 00:13:52 stefans-speaker volumio[4457]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Sep 01 00:13:52 stefans-speaker volumio[4457]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Sep 01 00:13:52 stefans-speaker volumio[4457]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Sep 01 00:13:52 stefans-speaker volumio[4457]: info: Adding plugin bluetooth to MyMusic Plugins Sep 01 00:13:52 stefans-speaker volumio[4457]: info: Adding plugin multiroom to MyMusic Plugins Sep 01 00:13:52 stefans-speaker volumio[4457]: info: Adding plugin metavolumio to MyMusic Plugins Sep 01 00:13:52 stefans-speaker volumio[4457]: info: Adding plugin cd_controller to MyMusic Plugins Sep 01 00:13:52 stefans-speaker volumio[4457]: info: Adding plugin qobuzconnect to MyMusic Plugins Sep 01 00:13:52 stefans-speaker volumio[4457]: info: Adding plugin smart_inputs to MyMusic Plugins Sep 01 00:13:52 stefans-speaker volumio[4457]: info: Adding plugin tidalconnect to MyMusic Plugins Sep 01 00:13:52 stefans-speaker volumio[4457]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Sep 01 00:13:53 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Sep 01 00:13:53 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:13:53 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:13:53 stefans-speaker go-librespot[4787]: go-librespot daemon starting... Sep 01 00:13:53 stefans-speaker go-librespot[4788]: time="2026-09-01T00:13:53+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:13:53 stefans-speaker go-librespot[4788]: time="2026-09-01T00:13:53+02:00" level=debug msg="app state loaded" Sep 01 00:13:53 stefans-speaker go-librespot[4788]: time="2026-09-01T00:13:53+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:13:53 stefans-speaker volumio[4457]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Sep 01 00:13:53 stefans-speaker volumio[4457]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Sep 01 00:13:53 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:13:53 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:13:53 stefans-speaker volumio[4457]: info: Starting MyVolumio Remote Streaming Endpoints Sep 01 00:13:53 stefans-speaker volumio[4457]: info: MyVolumio login type: Token Sep 01 00:13:53 stefans-speaker volumio[4457]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Sep 01 00:13:53 stefans-speaker volumio[4457]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Sep 01 00:13:54 stefans-speaker volumio[4457]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Sep 01 00:13:54 stefans-speaker volumio[4457]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Sep 01 00:13:54 stefans-speaker volumio[4457]: info: Streaming services startup Sep 01 00:13:54 stefans-speaker volumio[4457]: info: Starting Streaming Daemon Sep 01 00:13:54 stefans-speaker volumio[4457]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Sep 01 00:13:54 stefans-speaker sudo[4795]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:13:54 stefans-speaker sudo[4795]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Sep 01 00:13:54 stefans-speaker sudo[4795]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:13:54 stefans-speaker sudo[4795]: pam_unix(sudo:session): session closed for user root Sep 01 00:13:54 stefans-speaker volumio[4457]: info: Initializing connection to go-librespot Websocket Sep 01 00:13:54 stefans-speaker volumio[4457]: error: Cannot start Volumio Streaming Daemon Sep 01 00:13:54 stefans-speaker volumio[4457]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Sep 01 00:13:54 stefans-speaker volumio[4457]: sudo: unable to resolve host stefans-speaker: System error Sep 01 00:13:54 stefans-speaker volumio[4457]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Sep 01 00:13:54 stefans-speaker go-librespot[4788]: time="2026-09-01T00:13:54+02:00" level=debug msg="new websocket client" Sep 01 00:13:54 stefans-speaker volumio[4457]: info: Connection to go-librespot Websocket established Sep 01 00:13:55 stefans-speaker volumio[4457]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Sep 01 00:13:55 stefans-speaker volumio[4457]: info: MyVolumio token set successfully Sep 01 00:13:55 stefans-speaker volumio[4457]: info: MYVOLUMIO: Adding device Sep 01 00:13:55 stefans-speaker volumio[4457]: info: MYVOLUMIO: Evaluating Server Sep 01 00:13:55 stefans-speaker volumio[4457]: info: MyVolumio status changed Sep 01 00:13:55 stefans-speaker volumio[4457]: info: Streaming services startup Sep 01 00:13:55 stefans-speaker volumio[4457]: info: Starting Streaming Daemon Sep 01 00:13:55 stefans-speaker volumio[4457]: info: Removing browser output: myVolumio user plan is not superstar Sep 01 00:13:55 stefans-speaker volumio[4457]: info: Removing audio output: Sep 01 00:13:55 stefans-speaker volumio[4457]: info: Stoppping Tunnel 1 Sep 01 00:13:55 stefans-speaker sudo[4823]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:13:55 stefans-speaker sudo[4823]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Sep 01 00:13:55 stefans-speaker sudo[4823]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:13:55 stefans-speaker sudo[4825]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:13:55 stefans-speaker sudo[4825]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Sep 01 00:13:55 stefans-speaker sudo[4825]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:13:56 stefans-speaker systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Sep 01 00:13:56 stefans-speaker systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Sep 01 00:13:56 stefans-speaker sudo[4823]: pam_unix(sudo:session): session closed for user root Sep 01 00:13:56 stefans-speaker volumio[4457]: error: Cannot start Volumio Streaming Daemon Sep 01 00:13:56 stefans-speaker volumio[4457]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Sep 01 00:13:56 stefans-speaker volumio[4457]: sudo: unable to resolve host stefans-speaker: System error Sep 01 00:13:56 stefans-speaker volumio[4457]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Sep 01 00:13:56 stefans-speaker systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Sep 01 00:13:56 stefans-speaker systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Sep 01 00:13:56 stefans-speaker systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Sep 01 00:13:56 stefans-speaker systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Sep 01 00:13:56 stefans-speaker systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Sep 01 00:13:56 stefans-speaker systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Sep 01 00:13:56 stefans-speaker sudo[4825]: pam_unix(sudo:session): session closed for user root Sep 01 00:13:56 stefans-speaker volumio[4457]: info: Remote SSH Stopped Sep 01 00:13:56 stefans-speaker volumio[4457]: info: Setting Geolocation for MyVolumio to eu8 Sep 01 00:13:56 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:13:56 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:13:56 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:13:56 stefans-speaker volumio[4457]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Sep 01 00:13:57 stefans-speaker volumio[4457]: info: Updating MyVolumio device info Sep 01 00:13:57 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:13:57 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:13:57 stefans-speaker volumio[4457]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:13:57 stefans-speaker volumio[4457]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Sep 01 00:13:57 stefans-speaker volumio[4457]: info: Getting Spotify volume Sep 01 00:13:57 stefans-speaker volumio[4457]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Sep 01 00:13:57 stefans-speaker volumio[4457]: info: CoreCommandRouter::volumioGetState Sep 01 00:13:57 stefans-speaker volumio[4457]: info: CorePlayQueue::getTrack 0 Sep 01 00:13:57 stefans-speaker volumio[4457]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 Sep 01 00:13:57 stefans-speaker volumio[4457]: SPOTIFY: SPOTIFY VOLUME undefined Sep 01 00:13:57 stefans-speaker volumio[4457]: SPOTIFY: VOLUMIO VOLUME 70 Sep 01 00:13:57 stefans-speaker volumio[4457]: info: Aligning Spotify Volume to Volumio Volume Sep 01 00:13:57 stefans-speaker volumio[4457]: info: CoreCommandRouter::volumioGetState Sep 01 00:13:57 stefans-speaker volumio[4457]: info: CorePlayQueue::getTrack 0 Sep 01 00:13:57 stefans-speaker volumio[4457]: info: Setting Spotify Volume from Volumio: 70 Sep 01 00:13:58 stefans-speaker go-librespot[4788]: time="2026-09-01T00:13:58+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 00:13:58 stefans-speaker go-librespot[4788]: time="2026-09-01T00:13:58+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 01 00:13:58 stefans-speaker go-librespot[4788]: time="2026-09-01T00:13:58+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 01 00:13:58 stefans-speaker go-librespot[4788]: time="2026-09-01T00:13:58+02:00" level=info msg="zeroconf server listening on port 46191" Sep 01 00:13:58 stefans-speaker go-librespot[4788]: time="2026-09-01T00:13:58+02:00" level=debug msg="obtained new client token: AAHtF0g2TLEmvsr/YFxERYfbnkK52s5VNSTyvEp25ddLC8sO6G2mOmRqvuCNyxiq+0KG5UqEz9tquEzOG2kfzbxPmsfU+Cy7aPzJz71ZAgf4GU2JMeOKW9pmcptIFnxLEj6RxvkMz0Y3xC+7RqzW/0teUNJLGnb+rUHF/ngN3guKOnaZX2I+w8R0u9+1FzkhN73d13muwa9FHCHLsy3+mkqltO5Wmb0oq8+9LNbcCGvPmB6LWXbdVQ1DWvM=" Sep 01 00:13:58 stefans-speaker go-librespot[4788]: time="2026-09-01T00:13:58+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 00:13:58 stefans-speaker go-librespot[4788]: time="2026-09-01T00:13:58+02:00" level=debug msg="completed keyexchange" Sep 01 00:13:58 stefans-speaker go-librespot[4788]: time="2026-09-01T00:13:58+02:00" level=debug msg="completed challenge" Sep 01 00:13:58 stefans-speaker go-librespot[4788]: time="2026-09-01T00:13:58+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:13:58 stefans-speaker go-librespot[4788]: time="2026-09-01T00:13:58+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Sep 01 00:13:58 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:13:58 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:13:58 stefans-speaker volumio[4457]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 01 00:13:58 stefans-speaker volumio[4457]: Error: socket hang up Sep 01 00:13:58 stefans-speaker volumio[4457]: at connResetException (node:internal/errors:720:14) Sep 01 00:13:58 stefans-speaker volumio[4457]: at Socket.socketOnEnd (node:_http_client:519:23) Sep 01 00:13:58 stefans-speaker volumio[4457]: at Socket.emit (node:events:526:35) Sep 01 00:13:58 stefans-speaker volumio[4457]: at endReadableNT (node:internal/streams/readable:1376:12) Sep 01 00:13:58 stefans-speaker volumio[4457]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Sep 01 00:13:58 stefans-speaker volumio[4457]: code: 'ECONNRESET', Sep 01 00:13:58 stefans-speaker volumio[4457]: response: undefined Sep 01 00:13:58 stefans-speaker volumio[4457]: } Sep 01 00:13:58 stefans-speaker volumio[4457]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 01 00:13:59 stefans-speaker sudo[4842]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:13:59 stefans-speaker sudo[4842]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-09-01 00:12' Sep 01 00:13:59 stefans-speaker sudo[4842]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"