Sep 01 00:38:01 stefans-speaker volumio[21409]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Sep 01 00:38:01 stefans-speaker volumio[21409]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Sep 01 00:38:01 stefans-speaker volumio[21409]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Sep 01 00:38:01 stefans-speaker volumio[21409]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Sep 01 00:38:01 stefans-speaker volumio[21409]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Sep 01 00:38:01 stefans-speaker volumio[21409]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Sep 01 00:38:01 stefans-speaker volumio[21409]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Sep 01 00:38:01 stefans-speaker volumio[21409]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Sep 01 00:38:01 stefans-speaker volumio[21409]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Sep 01 00:38:01 stefans-speaker volumio[21409]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Sep 01 00:38:01 stefans-speaker volumio[21409]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Sep 01 00:38:01 stefans-speaker volumio[21409]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Sep 01 00:38:01 stefans-speaker volumio[21409]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Sep 01 00:38:01 stefans-speaker volumio[21409]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Sep 01 00:38:01 stefans-speaker volumio[21409]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Sep 01 00:38:01 stefans-speaker volumio[21409]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Sep 01 00:38:01 stefans-speaker volumio[21409]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Sep 01 00:38:01 stefans-speaker volumio[21409]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Sep 01 00:38:01 stefans-speaker volumio[21409]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Sep 01 00:38:01 stefans-speaker volumio[21409]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Sep 01 00:38:01 stefans-speaker volumio[21409]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Sep 01 00:38:01 stefans-speaker volumio[21409]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Sep 01 00:38:01 stefans-speaker volumio[21409]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Sep 01 00:38:01 stefans-speaker volumio[21409]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Sep 01 00:38:01 stefans-speaker volumio[21409]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Sep 01 00:38:01 stefans-speaker volumio[21409]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Sep 01 00:38:01 stefans-speaker volumio[21409]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Sep 01 00:38:01 stefans-speaker volumio[21409]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Sep 01 00:38:01 stefans-speaker volumio[21409]: info: Adding plugin bluetooth to MyMusic Plugins Sep 01 00:38:01 stefans-speaker volumio[21409]: info: Adding plugin multiroom to MyMusic Plugins Sep 01 00:38:01 stefans-speaker volumio[21409]: info: Adding plugin metavolumio to MyMusic Plugins Sep 01 00:38:01 stefans-speaker volumio[21409]: info: Adding plugin cd_controller to MyMusic Plugins Sep 01 00:38:01 stefans-speaker volumio[21409]: info: Adding plugin qobuzconnect to MyMusic Plugins Sep 01 00:38:01 stefans-speaker volumio[21409]: info: Adding plugin smart_inputs to MyMusic Plugins Sep 01 00:38:01 stefans-speaker volumio[21409]: info: Adding plugin tidalconnect to MyMusic Plugins Sep 01 00:38:01 stefans-speaker volumio[21409]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Sep 01 00:38:02 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Sep 01 00:38:02 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:38:02 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:38:02 stefans-speaker go-librespot[21749]: go-librespot daemon starting... Sep 01 00:38:02 stefans-speaker go-librespot[21750]: time="2026-09-01T00:38:02+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:38:02 stefans-speaker go-librespot[21750]: time="2026-09-01T00:38:02+02:00" level=debug msg="app state loaded" Sep 01 00:38:02 stefans-speaker go-librespot[21750]: time="2026-09-01T00:38:02+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:38:02 stefans-speaker go-librespot[21750]: time="2026-09-01T00:38:02+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 00:38:02 stefans-speaker go-librespot[21750]: time="2026-09-01T00:38:02+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:38:02 stefans-speaker go-librespot[21750]: time="2026-09-01T00:38:02+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:38:02 stefans-speaker go-librespot[21750]: time="2026-09-01T00:38:02+02:00" level=info msg="zeroconf server listening on port 39183" Sep 01 00:38:02 stefans-speaker go-librespot[21750]: time="2026-09-01T00:38:02+02:00" level=debug msg="obtained new client token: AAGTkwN+1hvLzJEQ8MyV9O6DzOHdqAdcttZ6W0ToefG7s6dJkhyKJ9s9h0Q9Cdpv5t+0eHg5DGE8j2UMsxMH9JWJjTpth0lUjbYWz3kiNMc9KOrgyOOCxOwTLSvj1psy9l2g/svyTde7RL+YGNr6zCaFcq9vfvVqq2y5w00w8KSMRxMOZOSpLw79MYuyWZ9Du9YMwDX92KU9djvpFe9GNWcH12qqBmrD5uuBkVcSvOjlu6LcLQKi6dnBJko=" Sep 01 00:38:02 stefans-speaker go-librespot[21750]: time="2026-09-01T00:38:02+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 00:38:02 stefans-speaker go-librespot[21750]: time="2026-09-01T00:38:02+02:00" level=debug msg="completed keyexchange" Sep 01 00:38:02 stefans-speaker go-librespot[21750]: time="2026-09-01T00:38:02+02:00" level=debug msg="completed challenge" Sep 01 00:38:02 stefans-speaker go-librespot[21750]: time="2026-09-01T00:38:02+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:38:02 stefans-speaker volumio[21409]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Sep 01 00:38:02 stefans-speaker volumio[21409]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Sep 01 00:38:02 stefans-speaker volumio[21409]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:38:02 stefans-speaker volumio[21409]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:38:02 stefans-speaker volumio[21409]: info: Starting MyVolumio Remote Streaming Endpoints Sep 01 00:38:02 stefans-speaker go-librespot[21750]: time="2026-09-01T00:38: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:38:02 stefans-speaker volumio[21409]: info: MyVolumio login type: Token Sep 01 00:38:02 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:38:02 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:38:02 stefans-speaker volumio[21409]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Sep 01 00:38:02 stefans-speaker volumio[21409]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Sep 01 00:38:03 stefans-speaker volumio[21409]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Sep 01 00:38:03 stefans-speaker volumio[21409]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Sep 01 00:38:03 stefans-speaker volumio[21409]: info: Streaming services startup Sep 01 00:38:03 stefans-speaker volumio[21409]: info: Starting Streaming Daemon Sep 01 00:38:03 stefans-speaker volumio[21409]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Sep 01 00:38:03 stefans-speaker sudo[21759]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:38:03 stefans-speaker sudo[21759]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Sep 01 00:38:03 stefans-speaker sudo[21759]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:38:03 stefans-speaker sudo[21759]: pam_unix(sudo:session): session closed for user root Sep 01 00:38:03 stefans-speaker volumio[21409]: info: Initializing connection to go-librespot Websocket Sep 01 00:38:03 stefans-speaker volumio[21409]: error: Cannot start Volumio Streaming Daemon Sep 01 00:38:03 stefans-speaker volumio[21409]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Sep 01 00:38:03 stefans-speaker volumio[21409]: sudo: unable to resolve host stefans-speaker: System error Sep 01 00:38:03 stefans-speaker volumio[21409]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Sep 01 00:38:03 stefans-speaker volumio[21409]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 00:38:04 stefans-speaker volumio[21409]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Sep 01 00:38:05 stefans-speaker volumio[21409]: info: MyVolumio token set successfully Sep 01 00:38:05 stefans-speaker volumio[21409]: info: MYVOLUMIO: Adding device Sep 01 00:38:05 stefans-speaker volumio[21409]: info: MYVOLUMIO: Evaluating Server Sep 01 00:38:05 stefans-speaker volumio[21409]: info: MyVolumio status changed Sep 01 00:38:05 stefans-speaker volumio[21409]: info: Streaming services startup Sep 01 00:38:05 stefans-speaker volumio[21409]: info: Starting Streaming Daemon Sep 01 00:38:05 stefans-speaker volumio[21409]: info: Removing browser output: myVolumio user plan is not superstar Sep 01 00:38:05 stefans-speaker volumio[21409]: info: Removing audio output: Sep 01 00:38:05 stefans-speaker volumio[21409]: info: Stoppping Tunnel 1 Sep 01 00:38:05 stefans-speaker sudo[21787]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:38:05 stefans-speaker sudo[21787]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Sep 01 00:38:05 stefans-speaker sudo[21787]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:38:05 stefans-speaker sudo[21789]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:38:05 stefans-speaker sudo[21789]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Sep 01 00:38:05 stefans-speaker sudo[21789]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:38:05 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:38:05 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:38:05 stefans-speaker sudo[21787]: pam_unix(sudo:session): session closed for user root Sep 01 00:38:05 stefans-speaker volumio[21409]: error: Cannot start Volumio Streaming Daemon Sep 01 00:38:05 stefans-speaker volumio[21409]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Sep 01 00:38:05 stefans-speaker volumio[21409]: sudo: unable to resolve host stefans-speaker: System error Sep 01 00:38:05 stefans-speaker volumio[21409]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Sep 01 00:38:05 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:38:05 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:38:05 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Sep 01 00:38:05 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:38:05 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:38:05 stefans-speaker sudo[21789]: pam_unix(sudo:session): session closed for user root Sep 01 00:38:05 stefans-speaker volumio[21409]: info: Remote SSH Stopped Sep 01 00:38:05 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:38:05 stefans-speaker volumio[21409]: info: Setting Geolocation for MyVolumio to eu8 Sep 01 00:38:05 stefans-speaker volumio[21409]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:38:05 stefans-speaker volumio[21409]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:38:05 stefans-speaker volumio[21409]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:38:05 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:38:05 stefans-speaker go-librespot[21793]: go-librespot daemon starting... Sep 01 00:38:05 stefans-speaker go-librespot[21794]: time="2026-09-01T00:38:05+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:38:05 stefans-speaker go-librespot[21794]: time="2026-09-01T00:38:05+02:00" level=debug msg="app state loaded" Sep 01 00:38:05 stefans-speaker go-librespot[21794]: time="2026-09-01T00:38:05+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:38:06 stefans-speaker go-librespot[21794]: time="2026-09-01T00:38: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:38:06 stefans-speaker go-librespot[21794]: time="2026-09-01T00:38: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:38:06 stefans-speaker go-librespot[21794]: time="2026-09-01T00:38: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:38:06 stefans-speaker go-librespot[21794]: time="2026-09-01T00:38:06+02:00" level=info msg="zeroconf server listening on port 36341" Sep 01 00:38:06 stefans-speaker go-librespot[21794]: time="2026-09-01T00:38:06+02:00" level=debug msg="obtained new client token: AAGgsKeIuMbR0oq0y9gaUNvHL+0YRo7FCskQO0XnEIGhoFICwFPaGffYtrW1BK+5Y9nwbDrdRsakYfirgKCR0hNSu+2crB6yOSjhjmT2ZAf4A0x5UqO3FoYWUxwQGJBSoaZ3vPYaqi9/gkT8yuzHhkI+O5E40b0sGSvFkJ5vMjf8i8EmHCQ9GAKyFDT1F+chlk51Yl0DIV+Sfs2IHhNWMxZN6dyRWtEgGi5ff/kFgUdldID1ak02K3kc" Sep 01 00:38:06 stefans-speaker go-librespot[21794]: time="2026-09-01T00:38:06+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 00:38:06 stefans-speaker go-librespot[21794]: time="2026-09-01T00:38:06+02:00" level=debug msg="completed keyexchange" Sep 01 00:38:06 stefans-speaker go-librespot[21794]: time="2026-09-01T00:38:06+02:00" level=debug msg="completed challenge" Sep 01 00:38:06 stefans-speaker go-librespot[21794]: time="2026-09-01T00:38:06+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:38:06 stefans-speaker go-librespot[21794]: time="2026-09-01T00:38: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:38:06 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:38:06 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:38:06 stefans-speaker volumio[21409]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Sep 01 00:38:06 stefans-speaker volumio[21409]: info: Updating MyVolumio device info Sep 01 00:38:06 stefans-speaker volumio[21409]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:38:06 stefans-speaker volumio[21409]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:38:06 stefans-speaker volumio[21409]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:38:06 stefans-speaker volumio[21409]: info: Initializing connection to go-librespot Websocket Sep 01 00:38:07 stefans-speaker volumio[21409]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 00:38:07 stefans-speaker volumio[21409]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Sep 01 00:38:09 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Sep 01 00:38:09 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:38:09 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:38:09 stefans-speaker go-librespot[21801]: go-librespot daemon starting... Sep 01 00:38:09 stefans-speaker go-librespot[21802]: time="2026-09-01T00:38:09+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:38:09 stefans-speaker go-librespot[21802]: time="2026-09-01T00:38:09+02:00" level=debug msg="app state loaded" Sep 01 00:38:09 stefans-speaker go-librespot[21802]: time="2026-09-01T00:38:09+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:38:10 stefans-speaker volumio[21409]: info: Initializing connection to go-librespot Websocket Sep 01 00:38:10 stefans-speaker go-librespot[21802]: time="2026-09-01T00:38:10+02:00" level=debug msg="new websocket client" Sep 01 00:38:10 stefans-speaker volumio[21409]: info: Connection to go-librespot Websocket established Sep 01 00:38:10 stefans-speaker go-librespot[21802]: time="2026-09-01T00:38:10+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 00:38:10 stefans-speaker go-librespot[21802]: time="2026-09-01T00:38:10+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:38:10 stefans-speaker go-librespot[21802]: time="2026-09-01T00:38:10+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:38:10 stefans-speaker go-librespot[21802]: time="2026-09-01T00:38:10+02:00" level=info msg="zeroconf server listening on port 42189" Sep 01 00:38:10 stefans-speaker go-librespot[21802]: time="2026-09-01T00:38:10+02:00" level=debug msg="obtained new client token: AAEIdsd/J17P2RSu4k2ujVGfEhU+6HJTMYU/hpjnMA+x69Ot8hJzWOLMAzV6FvzeLxXVnj8ULqKvGCz94g9u/h6vIGS6+sseXmASZGb0OtxWTSaP/cvMG0QBDtFEyBPcIzuycwaQKUCudjK6kcRjLH9G3i5uCUnINnlMLPuOO/kdBlKWXuw7e/ZkhwTvZSKzjNzv3qUbgGXTuTVNyCnnFJ1zvIvveBf0bBxJoiy/3mE0nA4yN8bsDzq/" Sep 01 00:38:10 stefans-speaker go-librespot[21802]: time="2026-09-01T00:38:10+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 00:38:10 stefans-speaker go-librespot[21802]: time="2026-09-01T00:38:10+02:00" level=debug msg="completed keyexchange" Sep 01 00:38:10 stefans-speaker go-librespot[21802]: time="2026-09-01T00:38:10+02:00" level=debug msg="completed challenge" Sep 01 00:38:10 stefans-speaker go-librespot[21802]: time="2026-09-01T00:38:10+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:38:10 stefans-speaker go-librespot[21802]: time="2026-09-01T00:38: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:38:10 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:38:10 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:38:10 stefans-speaker volumio[21409]: info: Connection to go-librespot Websocket closed Sep 01 00:38:10 stefans-speaker volumio[21409]: info: MYVOLUMIO: Adding device Sep 01 00:38:10 stefans-speaker volumio[21409]: info: MYVOLUMIO: Evaluating Server Sep 01 00:38:11 stefans-speaker volumio[21409]: info: Setting Geolocation for MyVolumio to eu8 Sep 01 00:38:11 stefans-speaker volumio[21409]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:38:11 stefans-speaker volumio[21409]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:38:11 stefans-speaker volumio[21409]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:38:11 stefans-speaker volumio[21409]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Sep 01 00:38:12 stefans-speaker volumio[21409]: info: Updating MyVolumio device info Sep 01 00:38:12 stefans-speaker volumio[21409]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:38:12 stefans-speaker volumio[21409]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:38:12 stefans-speaker volumio[21409]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:38:12 stefans-speaker volumio[21409]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Sep 01 00:38:13 stefans-speaker volumio[21409]: info: Getting Spotify volume Sep 01 00:38:13 stefans-speaker volumio[21409]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 01 00:38:13 stefans-speaker volumio[21409]: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 00:38:13 stefans-speaker volumio[21409]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Sep 01 00:38:13 stefans-speaker volumio[21409]: errno: -111, Sep 01 00:38:13 stefans-speaker volumio[21409]: code: 'ECONNREFUSED', Sep 01 00:38:13 stefans-speaker volumio[21409]: syscall: 'connect', Sep 01 00:38:13 stefans-speaker volumio[21409]: address: '127.0.0.1', Sep 01 00:38:13 stefans-speaker volumio[21409]: port: 9879, Sep 01 00:38:13 stefans-speaker volumio[21409]: response: undefined Sep 01 00:38:13 stefans-speaker volumio[21409]: } Sep 01 00:38:13 stefans-speaker volumio[21409]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 01 00:38:13 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Sep 01 00:38:13 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:38:13 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:38:13 stefans-speaker go-librespot[21853]: go-librespot daemon starting... Sep 01 00:38:13 stefans-speaker sudo[21856]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:38:13 stefans-speaker sudo[21856]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-09-01 00:37' Sep 01 00:38:13 stefans-speaker sudo[21856]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:38:13 stefans-speaker go-librespot[21857]: time="2026-09-01T00:38:13+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:38:13 stefans-speaker go-librespot[21857]: time="2026-09-01T00:38:13+02:00" level=debug msg="app state loaded" Sep 01 00:38:13 stefans-speaker go-librespot[21857]: time="2026-09-01T00:38:13+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:38:14 stefans-speaker sudo[21856]: pam_unix(sudo:session): session closed for user root Sep 01 00:38:14 stefans-speaker volumio[21409]: sudo: unable to resolve host stefans-speaker: System error Sep 01 00:38:14 stefans-speaker go-librespot[21857]: time="2026-09-01T00:38:14+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 00:38:14 stefans-speaker go-librespot[21857]: time="2026-09-01T00:38:14+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:38:14 stefans-speaker go-librespot[21857]: time="2026-09-01T00:38:14+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:38:14 stefans-speaker volumio-remote-updater[679]: [2026-09-01 00:38:14] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Sep 01 00:38:14 stefans-speaker volumio-remote-updater[679]: [2026-09-01 00:38:14] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Sep 01 00:38:14 stefans-speaker systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:38:14 stefans-speaker go-librespot[21857]: time="2026-09-01T00:38:14+02:00" level=info msg="zeroconf server listening on port 43281" Sep 01 00:38:14 stefans-speaker systemd[1]: volumio.service: Failed with result 'exit-code'. Sep 01 00:38:14 stefans-speaker systemd[1]: volumio.service: Consumed 33.425s CPU time. Sep 01 00:38:14 stefans-speaker systemd[1]: Started dynamicswap.service - dynamicswap service. Sep 01 00:38:14 stefans-speaker systemd[1]: dynamicswap.service: Deactivated successfully. Sep 01 00:38:14 stefans-speaker go-librespot[21857]: time="2026-09-01T00:38:14+02:00" level=debug msg="obtained new client token: AAEbY/TEjLSGUevdg5zlg2o348SbFl5+PM/aIR2mB0aOGaXAoyRZew/uBXUsA/QxJEDlS7M+0viAzb+KR1uozu0UwYBe8OoSlptqHai9AaibHC4gDq5t2cdJxArFZU04Ba5Q9IWoZbJq3JtelcM1IqmDGKFAEr2XNI6JgjE7Fd05tRf45eOF5kAZO5o2V/wqqNEdfwKUi495idXnpHvNmI4aWJeW/+TVCLq+tZ9bXoRE6Wy7V8WsyICW" Sep 01 00:38:14 stefans-speaker systemd[1]: volumio.service: Scheduled restart job, restart counter is at 250. Sep 01 00:38:14 stefans-speaker systemd[1]: Started dynamicswap.service - dynamicswap service. Sep 01 00:38:14 stefans-speaker systemd[1]: Stopped volumio.service - Volumio Backend Module. Sep 01 00:38:14 stefans-speaker systemd[1]: volumio.service: Consumed 33.425s CPU time. Sep 01 00:38:14 stefans-speaker systemd[1]: Started volumio.service - Volumio Backend Module. Sep 01 00:38:14 stefans-speaker go-librespot[21857]: time="2026-09-01T00:38:14+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 00:38:14 stefans-speaker systemd[1]: dynamicswap.service: Deactivated successfully. Sep 01 00:38:14 stefans-speaker go-librespot[21857]: time="2026-09-01T00:38:14+02:00" level=debug msg="completed keyexchange" Sep 01 00:38:14 stefans-speaker go-librespot[21857]: time="2026-09-01T00:38:14+02:00" level=debug msg="completed challenge" Sep 01 00:38:14 stefans-speaker go-librespot[21857]: time="2026-09-01T00:38:14+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:38:14 stefans-speaker go-librespot[21857]: time="2026-09-01T00:38: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:38:14 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:38:14 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:38:16 stefans-speaker volumio[21875]: info: ------------------------------------------- Sep 01 00:38:16 stefans-speaker volumio[21875]: info: ----- Volumio3 ---- Sep 01 00:38:16 stefans-speaker volumio[21875]: info: ------------------------------------------- Sep 01 00:38:16 stefans-speaker volumio[21875]: info: ----- System startup ---- Sep 01 00:38:16 stefans-speaker volumio[21875]: info: ------------------------------------------- Sep 01 00:38:17 stefans-speaker volumio[21875]: info: MYVOLUMIO Environment detected Sep 01 00:38:17 stefans-speaker volumio[21875]: info: Plugin folders cleanup Sep 01 00:38:17 stefans-speaker volumio[21875]: info: Scanning into folder /volumio/app/plugins/ Sep 01 00:38:17 stefans-speaker volumio[21875]: info: Scanning category audio_interface Sep 01 00:38:17 stefans-speaker volumio[21875]: info: Scanning category miscellanea Sep 01 00:38:17 stefans-speaker volumio[21875]: info: Scanning category music_service Sep 01 00:38:17 stefans-speaker volumio[21875]: info: Scanning category plugins.json Sep 01 00:38:17 stefans-speaker volumio[21875]: info: Scanning category system_controller Sep 01 00:38:17 stefans-speaker volumio[21875]: info: Scanning category user_interface Sep 01 00:38:17 stefans-speaker volumio[21875]: info: Scanning into folder /data/plugins/ Sep 01 00:38:17 stefans-speaker volumio[21875]: info: Scanning category music_service Sep 01 00:38:17 stefans-speaker volumio[21875]: info: Plugin folders cleanup completed Sep 01 00:38:17 stefans-speaker volumio[21875]: info: ------------------------------------------- Sep 01 00:38:17 stefans-speaker volumio[21875]: info: ----- Core plugins startup ---- Sep 01 00:38:17 stefans-speaker volumio[21875]: info: ------------------------------------------- Sep 01 00:38:17 stefans-speaker volumio[21875]: info: Loading plugins from folder /volumio/app/plugins/ Sep 01 00:38:17 stefans-speaker volumio[21875]: info: Adding plugin upnp to MyMusic Plugins Sep 01 00:38:17 stefans-speaker volumio[21875]: info: Adding plugin airplay_emulation to MyMusic Plugins Sep 01 00:38:17 stefans-speaker volumio[21875]: info: Adding plugin upnp_browser to MyMusic Plugins Sep 01 00:38:17 stefans-speaker volumio[21875]: info: Loading plugins from folder /data/plugins/ Sep 01 00:38:17 stefans-speaker volumio[21875]: info: Loading plugin "system"... Sep 01 00:38:17 stefans-speaker volumio[21875]: info: Loading plugin "appearance"... Sep 01 00:38:17 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Sep 01 00:38:17 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:38:17 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:38:17 stefans-speaker go-librespot[21906]: go-librespot daemon starting... Sep 01 00:38:17 stefans-speaker go-librespot[21907]: time="2026-09-01T00:38:17+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:38:17 stefans-speaker go-librespot[21907]: time="2026-09-01T00:38:17+02:00" level=debug msg="app state loaded" Sep 01 00:38:17 stefans-speaker go-librespot[21907]: time="2026-09-01T00:38:17+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:38:18 stefans-speaker go-librespot[21907]: time="2026-09-01T00:38:18+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 00:38:18 stefans-speaker go-librespot[21907]: time="2026-09-01T00:38:18+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:38:18 stefans-speaker go-librespot[21907]: time="2026-09-01T00:38:18+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:38:18 stefans-speaker go-librespot[21907]: time="2026-09-01T00:38:18+02:00" level=info msg="zeroconf server listening on port 43571" Sep 01 00:38:18 stefans-speaker go-librespot[21907]: time="2026-09-01T00:38:18+02:00" level=debug msg="obtained new client token: AAGyl7zx14MgO1g07eeR9JmaP62oWiTtKBnvBoaa6Gap0Bwj6OGPY4BfrTZsjRU4bqn6CX0i2B2byYnKX39AS3eZzWg98S8Cez/YNfZzFSiKAh96MNCP84Vr30yWSmZ/BDVnZINA/li/VhUFcXT8hAm0cPBYJdq6wwZu7aAmXcBqwtVni/e9+BMoGfkDMMMEjcJ15zMAVF9FGuKLabZ2pacF43UwG3m7WffXNJ0vjcs00bzIENIr133N" Sep 01 00:38:18 stefans-speaker go-librespot[21907]: time="2026-09-01T00:38:18+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Sep 01 00:38:18 stefans-speaker volumio[21875]: info: Loading plugin "network"... Sep 01 00:38:18 stefans-speaker volumio[21875]: info: Refreshing Cached IP Addresses Sep 01 00:38:18 stefans-speaker go-librespot[21907]: time="2026-09-01T00:38:18+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Sep 01 00:38:18 stefans-speaker sudo[21915]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:38:18 stefans-speaker sudo[21917]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:38:18 stefans-speaker volumio[21875]: info: Loading plugin "services"... Sep 01 00:38:18 stefans-speaker volumio[21875]: info: Loading plugin "alsa_controller"... Sep 01 00:38:18 stefans-speaker sudo[21915]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 01 00:38:18 stefans-speaker sudo[21915]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:38:18 stefans-speaker sudo[21915]: pam_unix(sudo:session): session closed for user root Sep 01 00:38:18 stefans-speaker go-librespot[21907]: time="2026-09-01T00:38:18+02:00" level=debug msg="completed keyexchange" Sep 01 00:38:18 stefans-speaker go-librespot[21907]: time="2026-09-01T00:38:18+02:00" level=debug msg="completed challenge" Sep 01 00:38:18 stefans-speaker sudo[21917]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 01 00:38:18 stefans-speaker sudo[21917]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:38:18 stefans-speaker sudo[21917]: pam_unix(sudo:session): session closed for user root Sep 01 00:38:18 stefans-speaker sudo[21924]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:38:18 stefans-speaker sudo[21924]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Sep 01 00:38:18 stefans-speaker sudo[21924]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:38:18 stefans-speaker go-librespot[21907]: time="2026-09-01T00:38:18+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:38:18 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 01 00:38:18 stefans-speaker volumio[21875]: info: Loading plugin "wizard"... Sep 01 00:38:18 stefans-speaker volumio[21875]: info: Loading plugin "networkfs"... Sep 01 00:38:18 stefans-speaker volumio[21875]: info: Starting Udev Watcher for removable devices Sep 01 00:38:18 stefans-speaker volumio[21875]: info: Ignoring mount for partition: boot Sep 01 00:38:18 stefans-speaker volumio[21875]: info: Ignoring mount for partition: volumio Sep 01 00:38:18 stefans-speaker volumio[21875]: info: Ignoring mount for partition: volumio_data Sep 01 00:38:18 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 01 00:38:18 stefans-speaker volumio[21875]: info: Loading plugin "volumio_command_line_client"... Sep 01 00:38:18 stefans-speaker volumio[21875]: info: Loading plugin "upnp"... Sep 01 00:38:18 stefans-speaker volumio[21875]: info: [1788215898565] Starting Upmpd Daemon Sep 01 00:38:18 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 01 00:38:18 stefans-speaker volumio[21875]: info: Loading plugin "my_music"... Sep 01 00:38:18 stefans-speaker volumio[21875]: info: Loading plugin "mpd"... Sep 01 00:38:18 stefans-speaker go-librespot[21907]: time="2026-09-01T00:38: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:38:18 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:38:18 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:38:18 stefans-speaker volumio[21875]: info: Loading plugin "upnp_browser"... Sep 01 00:38:19 stefans-speaker volumio-remote-updater[679]: [2026-09-01 00:38:19] [connect] Successful connection Sep 01 00:38:20 stefans-speaker volumio[21875]: info: Starting UPNP Browser Sep 01 00:38:20 stefans-speaker volumio[21875]: info: Loading plugin "alarm-clock"... Sep 01 00:38:20 stefans-speaker volumio[21875]: info: Loading plugin "airplay_emulation"... Sep 01 00:38:20 stefans-speaker volumio[21875]: info: Starting Shairport Sync Sep 01 00:38:20 stefans-speaker volumio[21875]: info: Loading plugin "last_100"... Sep 01 00:38:20 stefans-speaker volumio[21875]: info: Loading plugin "webradio"... Sep 01 00:38:20 stefans-speaker volumio[21875]: info: Loading plugin "i2s_dacs"... Sep 01 00:38:20 stefans-speaker volumio[21875]: info: I2S DAC not set, start Auto-detection Sep 01 00:38:20 stefans-speaker volumio[21875]: info: Loading plugin "volumiodiscovery"... Sep 01 00:38:20 stefans-speaker volumio[21875]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 01 00:38:20 stefans-speaker volumio[21875]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 01 00:38:20 stefans-speaker volumio[21875]: *** WARNING *** For more information see Sep 01 00:38:20 stefans-speaker volumio[21875]: *** 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:38:20 stefans-speaker volumio[21875]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 01 00:38:20 stefans-speaker volumio[21875]: *** WARNING *** For more information see Sep 01 00:38:20 stefans-speaker node[21875]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 01 00:38:20 stefans-speaker node[21875]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 01 00:38:20 stefans-speaker node[21875]: *** WARNING *** For more information see Sep 01 00:38:20 stefans-speaker node[21875]: *** 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:38:20 stefans-speaker node[21875]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 01 00:38:20 stefans-speaker node[21875]: *** WARNING *** For more information see Sep 01 00:38:20 stefans-speaker volumio[21875]: info: Applying required configuration parameters for plugin volumiodiscovery Sep 01 00:38:20 stefans-speaker volumio[21875]: info: Discovery: Started advertising with name: Stefan’s Speaker Sep 01 00:38:20 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 01 00:38:20 stefans-speaker volumio[21875]: info: Loading plugin "spop"... Sep 01 00:38:21 stefans-speaker sudo[21924]: pam_unix(sudo:session): session closed for user root Sep 01 00:38:21 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Sep 01 00:38:21 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:38:21 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:38:21 stefans-speaker go-librespot[21951]: go-librespot daemon starting... Sep 01 00:38:21 stefans-speaker volumio[21875]: info: Loading plugin "ytcr"... Sep 01 00:38:21 stefans-speaker go-librespot[21952]: time="2026-09-01T00:38:21+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:38:21 stefans-speaker go-librespot[21952]: time="2026-09-01T00:38:21+02:00" level=debug msg="app state loaded" Sep 01 00:38:21 stefans-speaker go-librespot[21952]: time="2026-09-01T00:38:21+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:38:22 stefans-speaker go-librespot[21952]: time="2026-09-01T00:38:22+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Sep 01 00:38:22 stefans-speaker go-librespot[21952]: time="2026-09-01T00:38:22+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:38:22 stefans-speaker go-librespot[21952]: time="2026-09-01T00:38:22+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:38:22 stefans-speaker go-librespot[21952]: time="2026-09-01T00:38:22+02:00" level=info msg="zeroconf server listening on port 42147" Sep 01 00:38:22 stefans-speaker go-librespot[21952]: time="2026-09-01T00:38:22+02:00" level=debug msg="obtained new client token: AAFU2WvnwKQl96ZCvNoymGVe1uEkl21C5ucVo/fi124zG6kqkWxtbUtfbvtHvdw7bgUvAXWAuKgErdPeBr0UvPLTQg1h4RXveVJuiWl67Okf5r9w1XPYZLx7f01EHL08CM0CvM5Qie3RXcsJKYsRkiDINJjOcizDTUoN0sLIw7mHEU/mdksx0bWt9FffGhQXlyZIM3rPmEtmsjaHiNEP5QBWJmqB0sYUtrg3GWqLJc6xVbm/hPPypPuq0Dw=" Sep 01 00:38:22 stefans-speaker go-librespot[21952]: time="2026-09-01T00:38:22+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 00:38:22 stefans-speaker go-librespot[21952]: time="2026-09-01T00:38:22+02:00" level=debug msg="completed keyexchange" Sep 01 00:38:22 stefans-speaker go-librespot[21952]: time="2026-09-01T00:38:22+02:00" level=debug msg="completed challenge" Sep 01 00:38:22 stefans-speaker go-librespot[21952]: time="2026-09-01T00:38:22+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:38:22 stefans-speaker go-librespot[21952]: time="2026-09-01T00:38: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:38:22 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:38:22 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:38:23 stefans-speaker volumio[21875]: info: Loading plugin "outputs"... Sep 01 00:38:23 stefans-speaker volumio[21875]: info: Loading plugin "albumart"... Sep 01 00:38:23 stefans-speaker volumio[21875]: info: Plugin example_plugin is not enabled Sep 01 00:38:23 stefans-speaker volumio[21875]: info: Loading plugin "inputs"... Sep 01 00:38:23 stefans-speaker volumio[21875]: info: Loading plugin "updater_comm"... Sep 01 00:38:23 stefans-speaker volumio[21875]: info: Plugin mpdemulation is not enabled Sep 01 00:38:23 stefans-speaker volumio[21875]: info: Loading plugin "rest_api"... Sep 01 00:38:23 stefans-speaker volumio[21875]: info: Loading plugin "websocket"... Sep 01 00:38:23 stefans-speaker volumio[21875]: info: Starting Socket.io Server version 1.7.4 Sep 01 00:38:23 stefans-speaker volumio[21875]: info: Loading i18n strings for locale nl Sep 01 00:38:23 stefans-speaker volumio[21875]: Updating browse sources language Sep 01 00:38:23 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 00:38:23 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 00:38:23 stefans-speaker volumio[21875]: info: CoreCommandRouter::initPlayerControls Sep 01 00:38:23 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:38:23 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:38:23 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:38:23 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:38:23 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:38:23 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:38:23 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:38:23 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:38:23 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 00:38:23 stefans-speaker volumio[21875]: Express server listening on port 3000 Sep 01 00:38:23 stefans-speaker volumio[21875]: [Metrics] WebUI: 8s 57.13ms Sep 01 00:38:23 stefans-speaker volumio[21875]: info: CoreStateMachine::resetVolumioState Sep 01 00:38:23 stefans-speaker volumio[21875]: info: CoreStateMachine::getcurrentVolume Sep 01 00:38:23 stefans-speaker volumio[21875]: info: CoreCommandRouter::volumioRetrievevolume Sep 01 00:38:23 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:38:23 stefans-speaker volumio[21875]: info: Cannot read play queue from file Sep 01 00:38:23 stefans-speaker volumio[21875]: info: Volumio Network Manager: Network status updated: 2 Sep 01 00:38:24 stefans-speaker volumio-remote-updater[679]: [2026-09-01 00:38:23] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1788215899 101 Sep 01 00:38:24 stefans-speaker volumio[21959]: Forking 3 albumart workers Sep 01 00:38:24 stefans-speaker volumio[21875]: 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: 1 Sep 01 00:38:24 stefans-speaker volumio[21875]: info: VolumeController:: Volume=70 Mute =false Sep 01 00:38:24 stefans-speaker volumio[21875]: info: CoreStateMachine::pushState Sep 01 00:38:24 stefans-speaker volumio[21875]: info: CorePlayQueue::getTrack 0 Sep 01 00:38:24 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 01 00:38:24 stefans-speaker volumio[21875]: info: CoreCommandRouter::volumioPushState Sep 01 00:38:24 stefans-speaker volumio[21875]: info: CoreStateMachine::updateTrackBlock Sep 01 00:38:24 stefans-speaker volumio[21875]: info: CorePlayQueue::getTrackBlock Sep 01 00:38:24 stefans-speaker volumio[21875]: info: CoreCommandRouter::volumioRetrievevolume Sep 01 00:38:24 stefans-speaker volumio[21875]: info: CoreStateMachine::setRepeat null single undefined Sep 01 00:38:24 stefans-speaker volumio[21875]: info: CoreStateMachine::pushState Sep 01 00:38:24 stefans-speaker volumio[21875]: info: CorePlayQueue::getTrack 0 Sep 01 00:38:24 stefans-speaker volumio[21875]: info: CoreCommandRouter::volumioPushState Sep 01 00:38:24 stefans-speaker volumio[21875]: info: CoreStateMachine::setRandom null Sep 01 00:38:24 stefans-speaker volumio[21875]: info: CoreStateMachine::pushState Sep 01 00:38:24 stefans-speaker volumio[21875]: info: CorePlayQueue::getTrack 0 Sep 01 00:38:24 stefans-speaker volumio[21875]: info: CoreCommandRouter::volumioPushState Sep 01 00:38:24 stefans-speaker volumio[21875]: info: Setting Device type: Raspberry PI Sep 01 00:38:24 stefans-speaker volumio[21875]: info: VolumeController:: Volume=70 Mute =false Sep 01 00:38:24 stefans-speaker volumio[21875]: info: CoreStateMachine::pushState Sep 01 00:38:24 stefans-speaker volumio[21875]: info: CorePlayQueue::getTrack 0 Sep 01 00:38:24 stefans-speaker volumio[21875]: info: CoreCommandRouter::volumioPushState Sep 01 00:38:24 stefans-speaker volumio[21875]: info: Completed loading Core Plugins Sep 01 00:38:24 stefans-speaker volumio[21875]: info: Preparing to generate the ALSA configuration file Sep 01 00:38:24 stefans-speaker volumio[21875]: info: Discovery: adding a312d0fa-c0eb-45ad-a25b-79fcdf237e8a Sep 01 00:38:24 stefans-speaker volumio[21875]: info: Discovery: Found device Stefan’s Speaker Sep 01 00:38:24 stefans-speaker volumio[21875]: info: CoreCommandRouter::volumioGetState Sep 01 00:38:24 stefans-speaker volumio[21875]: info: CorePlayQueue::getTrack 0 Sep 01 00:38:24 stefans-speaker volumio[21875]: info: Asound.conf file unchanged, so no further update is needed Sep 01 00:38:24 stefans-speaker volumio[21875]: info: Output device has changed, restarting MPD Sep 01 00:38:24 stefans-speaker volumio[21875]: info: Output device has changed, restarting Shairport Sync Sep 01 00:38:24 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:38:24 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:38:24 stefans-speaker sudo[22014]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:38:24 stefans-speaker sudo[22014]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 01 00:38:24 stefans-speaker sudo[22014]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:38:24 stefans-speaker sudo[22016]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:38:24 stefans-speaker volumio[21875]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 01 00:38:24 stefans-speaker volumio[21875]: info: ___________ START PLUGINS ___________ Sep 01 00:38:24 stefans-speaker sudo[22014]: pam_unix(sudo:session): session closed for user root Sep 01 00:38:24 stefans-speaker volumio[21875]: info: ControllerMpd::onStart: Initializing MPD Sep 01 00:38:24 stefans-speaker volumio[21875]: info: Creating MPD Configuration file Sep 01 00:38:24 stefans-speaker sudo[22016]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 01 00:38:24 stefans-speaker sudo[22016]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:38:24 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 00:38:24 stefans-speaker volumio[21875]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 01 00:38:24 stefans-speaker volumio[21875]: info: [1788215904613] CoreMusicLibrary::Adding element Media Servers Sep 01 00:38:24 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 00:38:24 stefans-speaker volumio[21875]: info: UPNP Browser: Client initialized successfully Sep 01 00:38:24 stefans-speaker systemd[1]: Stopping mpd.service - Music Player Daemon... Sep 01 00:38:24 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:38:24 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:38:24 stefans-speaker sudo[22024]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:38:24 stefans-speaker sudo[22026]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:38:24 stefans-speaker sudo[22024]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 01 00:38:24 stefans-speaker sudo[22024]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:38:24 stefans-speaker sudo[22026]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 01 00:38:24 stefans-speaker sudo[22024]: pam_unix(sudo:session): session closed for user root Sep 01 00:38:24 stefans-speaker sudo[22026]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:38:24 stefans-speaker volumio[21875]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 01 00:38:24 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:38:24 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:38:24 stefans-speaker systemd[1]: mpd.service: Deactivated successfully. Sep 01 00:38:24 stefans-speaker systemd[1]: Stopped mpd.service - Music Player Daemon. Sep 01 00:38:24 stefans-speaker systemd[1]: mpd.service: Consumed 4.550s CPU time. Sep 01 00:38:24 stefans-speaker systemd[1]: mpd.socket: Deactivated successfully. Sep 01 00:38:24 stefans-speaker volumio[21875]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 01 00:38:24 stefans-speaker volumio[21875]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 01 00:38:24 stefans-speaker volumio[21875]: info: [1788215904764] CoreMusicLibrary::Adding element Last_100 Sep 01 00:38:24 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 00:38:24 stefans-speaker volumio[21875]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 01 00:38:24 stefans-speaker volumio[21875]: info: [1788215904770] CoreMusicLibrary::Adding element Webradio Sep 01 00:38:24 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 00:38:24 stefans-speaker systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Sep 01 00:38:24 stefans-speaker systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Sep 01 00:38:24 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 01 00:38:24 stefans-speaker volumio[21875]: info: Initializing BBC Radios Sep 01 00:38:24 stefans-speaker systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Sep 01 00:38:24 stefans-speaker systemd[1]: Starting mpd.service - Music Player Daemon... Sep 01 00:38:24 stefans-speaker systemd[1]: mpd.service: Deactivated successfully. Sep 01 00:38:24 stefans-speaker systemd[1]: Stopped mpd.service - Music Player Daemon. Sep 01 00:38:24 stefans-speaker systemd[1]: mpd.socket: Deactivated successfully. Sep 01 00:38:24 stefans-speaker systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Sep 01 00:38:24 stefans-speaker systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Sep 01 00:38:24 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 01 00:38:24 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:38:24 stefans-speaker systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Sep 01 00:38:24 stefans-speaker systemd[1]: Starting mpd.service - Music Player Daemon... Sep 01 00:38:24 stefans-speaker volumio[21875]: info: Creating Spotify config file Sep 01 00:38:24 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:38:25 stefans-speaker sudo[22053]: root : unable to resolve host stefans-speaker: System error Sep 01 00:38:25 stefans-speaker sudo[22053]: sudo: unable to resolve host stefans-speaker: System error Sep 01 00:38:25 stefans-speaker sudo[22053]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Sep 01 00:38:25 stefans-speaker sudo[22053]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Sep 01 00:38:25 stefans-speaker sudo[22053]: pam_unix(sudo:session): session closed for user root Sep 01 00:38:25 stefans-speaker volumio[21875]: info: Volumio Calling Home Sep 01 00:38:25 stefans-speaker volumio[21875]: info: Discovery: this is already registered, a312d0fa-c0eb-45ad-a25b-79fcdf237e8a Sep 01 00:38:25 stefans-speaker volumio[21875]: info: Discovery: Found device Stefan’s Speaker Sep 01 00:38:25 stefans-speaker volumio[21875]: info: CoreCommandRouter::volumioGetState Sep 01 00:38:25 stefans-speaker volumio[21875]: info: CorePlayQueue::getTrack 0 Sep 01 00:38:25 stefans-speaker volumio[21875]: info: MPD Permissions set Sep 01 00:38:25 stefans-speaker volumio[21875]: info: MPD Permissions set Sep 01 00:38:25 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Sep 01 00:38:25 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:38:25 stefans-speaker volumio[21875]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Sep 01 00:38:25 stefans-speaker volumio[21875]: info: Volumio called home Sep 01 00:38:25 stefans-speaker volumio[21875]: info: Spotify config file written Sep 01 00:38:25 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:38:25 stefans-speaker go-librespot[22059]: go-librespot daemon starting... Sep 01 00:38:25 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:38:25 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:38:25 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:38:25 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:38:25 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:38:25 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:38:25 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:38:25 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:38:25 stefans-speaker go-librespot[22061]: time="2026-09-01T00:38:25+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:38:25 stefans-speaker go-librespot[22061]: time="2026-09-01T00:38:25+02:00" level=debug msg="app state loaded" Sep 01 00:38:25 stefans-speaker go-librespot[22061]: time="2026-09-01T00:38:25+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:38:25 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:38:25 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:38:25 stefans-speaker sudo[22062]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:38:25 stefans-speaker sudo[22062]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Sep 01 00:38:25 stefans-speaker sudo[22062]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:38:26 stefans-speaker systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Sep 01 00:38:26 stefans-speaker systemd[1]: go-librespot-daemon.service: Deactivated successfully. Sep 01 00:38:26 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:38:26 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:38:26 stefans-speaker go-librespot[22074]: go-librespot daemon starting... Sep 01 00:38:26 stefans-speaker sudo[22062]: pam_unix(sudo:session): session closed for user root Sep 01 00:38:26 stefans-speaker go-librespot[22075]: time="2026-09-01T00:38:26+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:38:26 stefans-speaker go-librespot[22075]: time="2026-09-01T00:38:26+02:00" level=debug msg="app state loaded" Sep 01 00:38:26 stefans-speaker go-librespot[22075]: time="2026-09-01T00:38:26+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:38:26 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:38:26 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:38:26 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:38:26 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:38:26 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:38:26 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:38:26 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:38:26 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:38:26 stefans-speaker volumio[21977]: Starting albumart workers Sep 01 00:38:26 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:38:26 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:38:26 stefans-speaker volumio[21875]: info: No need to fix Spotify hosts Sep 01 00:38:26 stefans-speaker volumio[21975]: Starting albumart workers Sep 01 00:38:26 stefans-speaker go-librespot[22075]: time="2026-09-01T00:38:26+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 00:38:26 stefans-speaker go-librespot[22075]: time="2026-09-01T00:38:26+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:38:26 stefans-speaker go-librespot[22075]: time="2026-09-01T00:38:26+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:38:26 stefans-speaker go-librespot[22075]: time="2026-09-01T00:38:26+02:00" level=info msg="zeroconf server listening on port 39177" Sep 01 00:38:26 stefans-speaker volumio[21976]: Starting albumart workers Sep 01 00:38:26 stefans-speaker go-librespot[22075]: time="2026-09-01T00:38:26+02:00" level=debug msg="obtained new client token: AAEjEHztKJf+aC7FIcMCmgC8DcZ0pGG7lJgYpyDwA4aCFPm/Ls+qZ3klTnfmYx8N5cVGdHiFFkj0tO9h2NGHn+AKzv2J8RKhlwU7qvuR0rwAWJArTmZkriGtL4gsOyMCafZZ0u+JH7RX9sMhqVgUpgkugMObp+BUS26ohRPMOEKQW+z2HvyaY8qazldPERwgZHNgTYT/FD5/Zv2rDUOtdittOuk4HKaPipR8sf+Muu4gsi7YMm7VAMH2gJ0=" Sep 01 00:38:26 stefans-speaker go-librespot[22075]: time="2026-09-01T00:38:26+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 00:38:26 stefans-speaker go-librespot[22075]: time="2026-09-01T00:38:26+02:00" level=debug msg="completed keyexchange" Sep 01 00:38:26 stefans-speaker go-librespot[22075]: time="2026-09-01T00:38:26+02:00" level=debug msg="completed challenge" Sep 01 00:38:26 stefans-speaker go-librespot[22075]: time="2026-09-01T00:38:26+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:38:27 stefans-speaker go-librespot[22075]: time="2026-09-01T00:38: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:38:27 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:38:27 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:38:27 stefans-speaker volumio[21875]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Sep 01 00:38:27 stefans-speaker volumio[21875]: SPOTIFY: BQCLDGrwZKhKu6geiwb1hpV4WbNxJd8_ry63-Iy1K67HixtGA9XyGH1AOjJRbm7UmUM5cQcxHyWoeExGpJ5XpYvDi2TRa2TnIJtScPYlQO4Qrmn9d0fZI73LMte_ZWbCwmd9h8AQcInH1w1_TPu_qOKF5bL9NaYMWhOA6tmi9BoT6TfpT29mcvJJ-ZRNuoVfMi6tekSdbupUplDgjEVZS1J4xmiNArL90w0qa2HXQh8-hHjB1jN9NnReaTH2JHdpkP9fX5-HVlkhJXrJIIuV71btMXZp5WSRiRiERWO5rr1XS-nEvYguV64-mMzFn_Y Sep 01 00:38:27 stefans-speaker volumio[21875]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Sep 01 00:38:27 stefans-speaker volumio[21875]: info: New Spotify access token = BQCLDGrwZKhKu6geiwb1hpV4WbNxJd8_ry63-Iy1K67HixtGA9XyGH1AOjJRbm7UmUM5cQcxHyWoeExGpJ5XpYvDi2TRa2TnIJtScPYlQO4Qrmn9d0fZI73LMte_ZWbCwmd9h8AQcInH1w1_TPu_qOKF5bL9NaYMWhOA6tmi9BoT6TfpT29mcvJJ-ZRNuoVfMi6tekSdbupUplDgjEVZS1J4xmiNArL90w0qa2HXQh8-hHjB1jN9NnReaTH2JHdpkP9fX5-HVlkhJXrJIIuV71btMXZp5WSRiRiERWO5rr1XS-nEvYguV64-mMzFn_Y Sep 01 00:38:27 stefans-speaker volumio[21875]: info: Spotify credentials grant success - running version from March 24, 2019 Sep 01 00:38:27 stefans-speaker volumio[21875]: info: Starting Shairport Sync Sep 01 00:38:27 stefans-speaker volumio[21875]: info: Starting Shairport Sync Sep 01 00:38:27 stefans-speaker volumio[21875]: info: Starting Shairport Sync Sep 01 00:38:27 stefans-speaker sudo[22092]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:38:27 stefans-speaker sudo[22092]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 01 00:38:27 stefans-speaker sudo[22092]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:38:27 stefans-speaker sudo[22099]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:38:27 stefans-speaker sudo[22099]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 01 00:38:27 stefans-speaker sudo[22099]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:38:27 stefans-speaker sudo[22097]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:38:27 stefans-speaker systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Sep 01 00:38:27 stefans-speaker sudo[22097]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 01 00:38:27 stefans-speaker sudo[22097]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:38:27 stefans-speaker systemd[1]: shairport-sync.service: Deactivated successfully. Sep 01 00:38:27 stefans-speaker systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Sep 01 00:38:27 stefans-speaker systemd[1]: shairport-sync.service: Consumed 1.880s CPU time. Sep 01 00:38:27 stefans-speaker systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Sep 01 00:38:27 stefans-speaker sudo[22092]: pam_unix(sudo:session): session closed for user root Sep 01 00:38:27 stefans-speaker sudo[22099]: pam_unix(sudo:session): session closed for user root Sep 01 00:38:27 stefans-speaker systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Sep 01 00:38:27 stefans-speaker systemd[1]: shairport-sync.service: Deactivated successfully. Sep 01 00:38:27 stefans-speaker systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Sep 01 00:38:27 stefans-speaker systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Sep 01 00:38:27 stefans-speaker sudo[22097]: pam_unix(sudo:session): session closed for user root Sep 01 00:38:27 stefans-speaker volumio[21875]: info: Shairport-Sync Started Sep 01 00:38:27 stefans-speaker volumio[21875]: Error adding Membership: Error: addMembership EINVAL Sep 01 00:38:27 stefans-speaker volumio[21875]: info: Shairport-Sync Started Sep 01 00:38:28 stefans-speaker volumio[21875]: info: Shairport-Sync Started Sep 01 00:38:28 stefans-speaker volumio[21875]: info: CoreCommandRouter::volumioGetState Sep 01 00:38:28 stefans-speaker volumio[21875]: info: CorePlayQueue::getTrack 0 Sep 01 00:38:28 stefans-speaker volumio[21875]: 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:38:28 stefans-speaker volumio[21875]: info: Spotify Successfully logged in Sep 01 00:38:28 stefans-speaker volumio[21875]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 01 00:38:28 stefans-speaker volumio[21875]: info: [1788215908208] CoreMusicLibrary::Adding element Spotify Sep 01 00:38:28 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 00:38:28 stefans-speaker volumio[21875]: Cannot find translation for source Spotify Sep 01 00:38:28 stefans-speaker sudo[22146]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:38:28 stefans-speaker volumio[21875]: info: [yt-cast-receiver] DIAL server listening on port 8098 Sep 01 00:38:28 stefans-speaker sudo[22148]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:38:28 stefans-speaker volumio[21875]: info: CoreCommandRouter::volumioRetrievevolume Sep 01 00:38:28 stefans-speaker sudo[22146]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 01 00:38:28 stefans-speaker sudo[22146]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:38:28 stefans-speaker sudo[22146]: pam_unix(sudo:session): session closed for user root Sep 01 00:38:28 stefans-speaker sudo[22148]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 01 00:38:28 stefans-speaker sudo[22148]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:38:28 stefans-speaker sudo[22148]: pam_unix(sudo:session): session closed for user root Sep 01 00:38:28 stefans-speaker volumio[21875]: info: VolumeController:: Volume=70 Mute =false Sep 01 00:38:28 stefans-speaker volumio[21875]: info: CoreCommandRouter::volumioGetState Sep 01 00:38:28 stefans-speaker volumio[21875]: info: CorePlayQueue::getTrack 0 Sep 01 00:38:28 stefans-speaker volumio[21875]: info: CoreStateMachine::pushState Sep 01 00:38:28 stefans-speaker volumio[21875]: info: CorePlayQueue::getTrack 0 Sep 01 00:38:28 stefans-speaker volumio[21875]: info: CoreCommandRouter::volumioPushState Sep 01 00:38:28 stefans-speaker sudo[22154]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:38:28 stefans-speaker sudo[22154]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Sep 01 00:38:28 stefans-speaker sudo[22154]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:38:28 stefans-speaker sudo[22154]: pam_unix(sudo:session): session closed for user root Sep 01 00:38:28 stefans-speaker volumio[21875]: info: Upmpdcli Daemon Started Sep 01 00:38:29 stefans-speaker volumio[21875]: info: go-librespot daemon successfully initialized Sep 01 00:38:29 stefans-speaker mpd[22055]: 2026-09-01T00:38:29 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Sep 01 00:38:29 stefans-speaker systemd[1]: Started mpd.service - Music Player Daemon. Sep 01 00:38:29 stefans-speaker sudo[22016]: pam_unix(sudo:session): session closed for user root Sep 01 00:38:29 stefans-speaker sudo[22026]: pam_unix(sudo:session): session closed for user root Sep 01 00:38:29 stefans-speaker volumio[21875]: error: MPD error: The expression evaluated to a falsy value: Sep 01 00:38:29 stefans-speaker volumio[21875]: assert.ok(self.idling) Sep 01 00:38:29 stefans-speaker volumio[21875]: error: The expression evaluated to a falsy value: Sep 01 00:38:29 stefans-speaker volumio[21875]: assert.ok(self.idling) Sep 01 00:38:29 stefans-speaker volumio[21875]: error: updateQueue error: null Sep 01 00:38:29 stefans-speaker volumio[21875]: info: MPD running with PID22055 Sep 01 00:38:29 stefans-speaker volumio[21875]: ,establishing connection Sep 01 00:38:29 stefans-speaker volumio[21875]: info: Completed starting Core Plugins Sep 01 00:38:29 stefans-speaker volumio[21875]: info: ------------------------------------------- Sep 01 00:38:29 stefans-speaker volumio[21875]: info: ----- MyVolumio plugins startup ---- Sep 01 00:38:29 stefans-speaker volumio[21875]: info: ------------------------------------------- Sep 01 00:38:30 stefans-speaker volumio[21875]: info: [MyVolumio PluginManager] Fetching plans data.... Sep 01 00:38:30 stefans-speaker volumio[21875]: error: updateQueue error: null Sep 01 00:38:30 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Sep 01 00:38:30 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:38:30 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:38:30 stefans-speaker go-librespot[22162]: go-librespot daemon starting... Sep 01 00:38:30 stefans-speaker go-librespot[22163]: time="2026-09-01T00:38:30+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:38:30 stefans-speaker go-librespot[22163]: time="2026-09-01T00:38:30+02:00" level=debug msg="app state loaded" Sep 01 00:38:30 stefans-speaker go-librespot[22163]: time="2026-09-01T00:38:30+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:38:30 stefans-speaker go-librespot[22163]: time="2026-09-01T00:38:30+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 00:38:30 stefans-speaker go-librespot[22163]: time="2026-09-01T00:38:30+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:38:30 stefans-speaker go-librespot[22163]: time="2026-09-01T00:38:30+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:38:30 stefans-speaker go-librespot[22163]: time="2026-09-01T00:38:30+02:00" level=info msg="zeroconf server listening on port 41781" Sep 01 00:38:30 stefans-speaker go-librespot[22163]: time="2026-09-01T00:38:30+02:00" level=debug msg="obtained new client token: AAGHTZJskawdA4zbIQDugY5OoUP2Jw9gON9vrIuOc23+Aesf8I46MEZC7a+Xc5YjL5Gy98aocF+y0dI/yZnNwWbsnQK9Pio1SJaRjlvbBlI9pLBKSZ53uA6jQ8ZD00GKj/+YZ1iA2P5Iw35Kwu6fQTUpLPeWOI9CSE1pd/knS8773prXuVKSDkNwbcwV0QdilTq0Nr8PeLLIs7eKg0Heo5PE1iutHpE70HRDoB0Up9DE3P+sPDWbEf27dNY=" Sep 01 00:38:30 stefans-speaker go-librespot[22163]: time="2026-09-01T00:38:30+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 00:38:30 stefans-speaker go-librespot[22163]: time="2026-09-01T00:38:30+02:00" level=debug msg="completed keyexchange" Sep 01 00:38:30 stefans-speaker go-librespot[22163]: time="2026-09-01T00:38:30+02:00" level=debug msg="completed challenge" Sep 01 00:38:30 stefans-speaker go-librespot[22163]: time="2026-09-01T00:38:30+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:38:31 stefans-speaker go-librespot[22163]: time="2026-09-01T00:38: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:38:31 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:38:31 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:38:32 stefans-speaker volumio[21875]: info: Initializing connection to go-librespot Websocket Sep 01 00:38:32 stefans-speaker volumio[21875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 00:38:32 stefans-speaker sudo[22173]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:38:32 stefans-speaker sudo[22175]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:38:32 stefans-speaker sudo[22173]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Sep 01 00:38:32 stefans-speaker sudo[22173]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:38:32 stefans-speaker sudo[22175]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Sep 01 00:38:32 stefans-speaker sudo[22175]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:38:32 stefans-speaker systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Sep 01 00:38:32 stefans-speaker systemd[1]: mpd_monitor.service: Deactivated successfully. Sep 01 00:38:32 stefans-speaker systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Sep 01 00:38:33 stefans-speaker systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Sep 01 00:38:33 stefans-speaker sudo[22175]: pam_unix(sudo:session): session closed for user root Sep 01 00:38:33 stefans-speaker sudo[22173]: pam_unix(sudo:session): session closed for user root Sep 01 00:38:33 stefans-speaker mpd_monitor.sh[22178]: MPD Monitor Service: Starting MPD Monitor Service Sep 01 00:38:33 stefans-speaker volumio[21875]: info: Successfully started MPD Monitor Sep 01 00:38:33 stefans-speaker volumio[21875]: info: Successfully started MPD Monitor Sep 01 00:38:34 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Sep 01 00:38:34 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:38:34 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:38:34 stefans-speaker go-librespot[22182]: go-librespot daemon starting... Sep 01 00:38:34 stefans-speaker go-librespot[22183]: time="2026-09-01T00:38:34+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:38:34 stefans-speaker go-librespot[22183]: time="2026-09-01T00:38:34+02:00" level=debug msg="app state loaded" Sep 01 00:38:34 stefans-speaker go-librespot[22183]: time="2026-09-01T00:38:34+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:38:34 stefans-speaker go-librespot[22183]: time="2026-09-01T00:38:34+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:38:34 stefans-speaker go-librespot[22183]: time="2026-09-01T00:38:34+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:38:34 stefans-speaker go-librespot[22183]: time="2026-09-01T00:38:34+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:38:34 stefans-speaker go-librespot[22183]: time="2026-09-01T00:38:34+02:00" level=info msg="zeroconf server listening on port 38539" Sep 01 00:38:34 stefans-speaker go-librespot[22183]: time="2026-09-01T00:38:34+02:00" level=debug msg="obtained new client token: AAGAE04Nk/aZhaS4pqSBjjpuJURoseTBAs/jm3g/XOVYt0B874hA1ENSRXPGkDg2QLinn5nWJA76+arqVymRA8XFYkSufkSP6VsOeMCpQkCp2zVeLB8SGz4bEJchNt2oFRtsnfhc/8Eh1fR43ZL7Kl9nIfkzJyNIHDL+88C0RnFX5ZEnnJwsNcjCgFBtXijj9YgvM+0CVRwdeKZoQ6+c8DCn17jpEpl9QWLAKtWHYC0xxnSBfdgfOe8aaWg=" Sep 01 00:38:34 stefans-speaker go-librespot[22183]: time="2026-09-01T00:38:34+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 00:38:34 stefans-speaker go-librespot[22183]: time="2026-09-01T00:38:34+02:00" level=debug msg="completed keyexchange" Sep 01 00:38:34 stefans-speaker go-librespot[22183]: time="2026-09-01T00:38:34+02:00" level=debug msg="completed challenge" Sep 01 00:38:34 stefans-speaker go-librespot[22183]: time="2026-09-01T00:38:34+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:38:34 stefans-speaker go-librespot[22183]: time="2026-09-01T00:38:34+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:38:34 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:38:34 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:38:34 stefans-speaker volumio[21875]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Sep 01 00:38:35 stefans-speaker volumio[21875]: info: Initializing connection to go-librespot Websocket Sep 01 00:38:35 stefans-speaker volumio[21875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 00:38:37 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Sep 01 00:38:37 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:38:37 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:38:37 stefans-speaker go-librespot[22191]: go-librespot daemon starting... Sep 01 00:38:37 stefans-speaker go-librespot[22192]: time="2026-09-01T00:38:37+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:38:37 stefans-speaker go-librespot[22192]: time="2026-09-01T00:38:37+02:00" level=debug msg="app state loaded" Sep 01 00:38:37 stefans-speaker go-librespot[22192]: time="2026-09-01T00:38:37+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:38:38 stefans-speaker go-librespot[22192]: time="2026-09-01T00:38: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:38:38 stefans-speaker go-librespot[22192]: time="2026-09-01T00:38: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:38:38 stefans-speaker go-librespot[22192]: time="2026-09-01T00:38: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:38:38 stefans-speaker go-librespot[22192]: time="2026-09-01T00:38:38+02:00" level=info msg="zeroconf server listening on port 38221" Sep 01 00:38:38 stefans-speaker go-librespot[22192]: time="2026-09-01T00:38:38+02:00" level=debug msg="obtained new client token: AAGt3du1MwoN4vp4ZwFWONcyFXXqEjlFxO9KWUBm8UlNOPJnZyTjIITZqI7SVZ1hJWXhPUyMs4khica/2TVkaOWLZmSclT3+M9C1poqWxavU8BpexuvydAPTymHQvrA4LfXttrN1tp4x539JyGzgqH+cRKGUeFUWHbI6Y41A9RZFgTq5Tf7Rg/6lbX/iZmUMza/Gj4R+OcYUsS3A876MM9jQQUsm4lxqe3DVYJJSOnNjtq47jVUw+15e" Sep 01 00:38:38 stefans-speaker go-librespot[22192]: time="2026-09-01T00:38:38+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 00:38:38 stefans-speaker volumio[21875]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Sep 01 00:38:38 stefans-speaker volumio[21875]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Sep 01 00:38:38 stefans-speaker volumio[21875]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Sep 01 00:38:38 stefans-speaker volumio[21875]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Sep 01 00:38:38 stefans-speaker volumio[21875]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Sep 01 00:38:38 stefans-speaker volumio[21875]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Sep 01 00:38:38 stefans-speaker volumio[21875]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Sep 01 00:38:38 stefans-speaker volumio[21875]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Sep 01 00:38:38 stefans-speaker volumio[21875]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Sep 01 00:38:38 stefans-speaker volumio[21875]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Sep 01 00:38:38 stefans-speaker volumio[21875]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Sep 01 00:38:38 stefans-speaker volumio[21875]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Sep 01 00:38:38 stefans-speaker volumio[21875]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Sep 01 00:38:38 stefans-speaker volumio[21875]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Sep 01 00:38:38 stefans-speaker volumio[21875]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Sep 01 00:38:38 stefans-speaker volumio[21875]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Sep 01 00:38:38 stefans-speaker volumio[21875]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Sep 01 00:38:38 stefans-speaker volumio[21875]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Sep 01 00:38:38 stefans-speaker volumio[21875]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Sep 01 00:38:38 stefans-speaker volumio[21875]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Sep 01 00:38:38 stefans-speaker volumio[21875]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Sep 01 00:38:38 stefans-speaker volumio[21875]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Sep 01 00:38:38 stefans-speaker volumio[21875]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Sep 01 00:38:38 stefans-speaker volumio[21875]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Sep 01 00:38:38 stefans-speaker volumio[21875]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Sep 01 00:38:38 stefans-speaker volumio[21875]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Sep 01 00:38:38 stefans-speaker volumio[21875]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Sep 01 00:38:38 stefans-speaker volumio[21875]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Sep 01 00:38:38 stefans-speaker volumio[21875]: info: Adding plugin bluetooth to MyMusic Plugins Sep 01 00:38:38 stefans-speaker volumio[21875]: info: Adding plugin multiroom to MyMusic Plugins Sep 01 00:38:38 stefans-speaker volumio[21875]: info: Adding plugin metavolumio to MyMusic Plugins Sep 01 00:38:38 stefans-speaker volumio[21875]: info: Adding plugin cd_controller to MyMusic Plugins Sep 01 00:38:38 stefans-speaker volumio[21875]: info: Adding plugin qobuzconnect to MyMusic Plugins Sep 01 00:38:38 stefans-speaker volumio[21875]: info: Adding plugin smart_inputs to MyMusic Plugins Sep 01 00:38:38 stefans-speaker volumio[21875]: info: Adding plugin tidalconnect to MyMusic Plugins Sep 01 00:38:38 stefans-speaker volumio[21875]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Sep 01 00:38:38 stefans-speaker go-librespot[22192]: time="2026-09-01T00:38:38+02:00" level=debug msg="completed keyexchange" Sep 01 00:38:38 stefans-speaker go-librespot[22192]: time="2026-09-01T00:38:38+02:00" level=debug msg="completed challenge" Sep 01 00:38:38 stefans-speaker go-librespot[22192]: time="2026-09-01T00:38:38+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:38:38 stefans-speaker go-librespot[22192]: time="2026-09-01T00:38:38+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:38:38 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:38:38 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:38:39 stefans-speaker volumio[21875]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Sep 01 00:38:39 stefans-speaker volumio[21875]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Sep 01 00:38:39 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:38:39 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:38:39 stefans-speaker volumio[21875]: info: Starting MyVolumio Remote Streaming Endpoints Sep 01 00:38:39 stefans-speaker volumio[21875]: info: MyVolumio login type: Token Sep 01 00:38:39 stefans-speaker volumio[21875]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Sep 01 00:38:39 stefans-speaker volumio[21875]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Sep 01 00:38:40 stefans-speaker volumio[21875]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Sep 01 00:38:40 stefans-speaker volumio[21875]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Sep 01 00:38:40 stefans-speaker volumio[21875]: info: Streaming services startup Sep 01 00:38:40 stefans-speaker volumio[21875]: info: Starting Streaming Daemon Sep 01 00:38:40 stefans-speaker sudo[22214]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:38:40 stefans-speaker volumio[21875]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Sep 01 00:38:40 stefans-speaker sudo[22214]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Sep 01 00:38:40 stefans-speaker sudo[22214]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:38:40 stefans-speaker sudo[22214]: pam_unix(sudo:session): session closed for user root Sep 01 00:38:40 stefans-speaker volumio[21875]: info: Initializing connection to go-librespot Websocket Sep 01 00:38:40 stefans-speaker volumio[21875]: error: Cannot start Volumio Streaming Daemon Sep 01 00:38:40 stefans-speaker volumio[21875]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Sep 01 00:38:40 stefans-speaker volumio[21875]: sudo: unable to resolve host stefans-speaker: System error Sep 01 00:38:40 stefans-speaker volumio[21875]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Sep 01 00:38:40 stefans-speaker volumio[21875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 00:38:41 stefans-speaker volumio[21875]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Sep 01 00:38:41 stefans-speaker volumio[21875]: info: MyVolumio token set successfully Sep 01 00:38:41 stefans-speaker volumio[21875]: info: MYVOLUMIO: Adding device Sep 01 00:38:41 stefans-speaker volumio[21875]: info: MYVOLUMIO: Evaluating Server Sep 01 00:38:41 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Sep 01 00:38:41 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:38:41 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:38:41 stefans-speaker go-librespot[22231]: go-librespot daemon starting... Sep 01 00:38:41 stefans-speaker go-librespot[22237]: time="2026-09-01T00:38:41+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:38:41 stefans-speaker go-librespot[22237]: time="2026-09-01T00:38:41+02:00" level=debug msg="app state loaded" Sep 01 00:38:41 stefans-speaker go-librespot[22237]: time="2026-09-01T00:38:41+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:38:41 stefans-speaker volumio[21875]: info: MyVolumio status changed Sep 01 00:38:41 stefans-speaker volumio[21875]: info: Streaming services startup Sep 01 00:38:41 stefans-speaker volumio[21875]: info: Starting Streaming Daemon Sep 01 00:38:42 stefans-speaker volumio[21875]: info: Removing browser output: myVolumio user plan is not superstar Sep 01 00:38:42 stefans-speaker volumio[21875]: info: Removing audio output: Sep 01 00:38:42 stefans-speaker volumio[21875]: info: Stoppping Tunnel 1 Sep 01 00:38:42 stefans-speaker sudo[22251]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:38:42 stefans-speaker sudo[22251]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Sep 01 00:38:42 stefans-speaker sudo[22251]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:38:42 stefans-speaker sudo[22253]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:38:42 stefans-speaker sudo[22253]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Sep 01 00:38:42 stefans-speaker sudo[22253]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:38:42 stefans-speaker sudo[22251]: pam_unix(sudo:session): session closed for user root Sep 01 00:38:42 stefans-speaker volumio[21875]: error: Cannot start Volumio Streaming Daemon Sep 01 00:38:42 stefans-speaker volumio[21875]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Sep 01 00:38:42 stefans-speaker volumio[21875]: sudo: unable to resolve host stefans-speaker: System error Sep 01 00:38:42 stefans-speaker volumio[21875]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Sep 01 00:38: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:38: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:38: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:38: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:38: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:38: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:38:42 stefans-speaker go-librespot[22237]: time="2026-09-01T00:38: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 00:38:42 stefans-speaker go-librespot[22237]: time="2026-09-01T00:38:42+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:38:42 stefans-speaker go-librespot[22237]: time="2026-09-01T00:38:42+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:38: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:38: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:38:42 stefans-speaker sudo[22253]: pam_unix(sudo:session): session closed for user root Sep 01 00:38:42 stefans-speaker volumio[21875]: info: Remote SSH Stopped Sep 01 00:38:42 stefans-speaker go-librespot[22237]: time="2026-09-01T00:38:42+02:00" level=info msg="zeroconf server listening on port 41693" Sep 01 00:38:42 stefans-speaker go-librespot[22237]: time="2026-09-01T00:38:42+02:00" level=debug msg="obtained new client token: AAHx3arqVLgPALTt1X59febyyrobfJmNZCGP0+zKsj3GU2/Z8r9jSxTY6GUxOf2/CmZPSe5EevNtCMq002Bm6+sioK7hiM2hWZcwEDUh+l5vtFiiBojJFZGFghT+mHlKCRRIrxJ+I5xXooWxh/w981LEXw27nETmAUuduRF3iP1OCZI+y85kJ6xiR6go4g/Epsr1yAzYMwnDsAHGIY+93C9ocwEz2VPIxrauwr+tVUoWrZpdAEgRMAIof6Y=" Sep 01 00:38:42 stefans-speaker go-librespot[22237]: time="2026-09-01T00:38:42+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 00:38:42 stefans-speaker go-librespot[22237]: time="2026-09-01T00:38:42+02:00" level=debug msg="completed keyexchange" Sep 01 00:38:42 stefans-speaker go-librespot[22237]: time="2026-09-01T00:38:42+02:00" level=debug msg="completed challenge" Sep 01 00:38:42 stefans-speaker go-librespot[22237]: time="2026-09-01T00:38:42+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:38:42 stefans-speaker go-librespot[22237]: time="2026-09-01T00:38:42+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:38:42 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:38:42 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:38:43 stefans-speaker volumio[21875]: info: Initializing connection to go-librespot Websocket Sep 01 00:38:43 stefans-speaker volumio[21875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 00:38:43 stefans-speaker volumio[21875]: info: Setting Geolocation for MyVolumio to eu8 Sep 01 00:38:43 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:38:43 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:38:43 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:38:44 stefans-speaker volumio[21875]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Sep 01 00:38:44 stefans-speaker volumio[21875]: info: Updating MyVolumio device info Sep 01 00:38:44 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:38:44 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:38:44 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:38:45 stefans-speaker volumio[21875]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Sep 01 00:38:45 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Sep 01 00:38:45 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:38:45 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:38:45 stefans-speaker go-librespot[22258]: go-librespot daemon starting... Sep 01 00:38:45 stefans-speaker go-librespot[22259]: time="2026-09-01T00:38:45+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:38:45 stefans-speaker go-librespot[22259]: time="2026-09-01T00:38:45+02:00" level=debug msg="app state loaded" Sep 01 00:38:45 stefans-speaker go-librespot[22259]: time="2026-09-01T00:38:45+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:38:46 stefans-speaker go-librespot[22259]: time="2026-09-01T00:38: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:38:46 stefans-speaker go-librespot[22259]: time="2026-09-01T00:38: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:38:46 stefans-speaker go-librespot[22259]: time="2026-09-01T00:38: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:38:46 stefans-speaker go-librespot[22259]: time="2026-09-01T00:38:46+02:00" level=info msg="zeroconf server listening on port 43931" Sep 01 00:38:46 stefans-speaker go-librespot[22259]: time="2026-09-01T00:38:46+02:00" level=debug msg="obtained new client token: AAHvqbhSNwqRE0/TqG2kG0dNU9ZpgxWx95+/Qa4tgY4WNTY6TKBIIoIJqne89lUtjLSaCRvDxXIg9zOzRxblG4LkMeseMpZyoCdX6eRX5ahGHAXADbbhUybjBSBD4R85VlP9Y2ErG5KzAT+EVTI3oH77jIwox5WonNIoMpdNHRmbHpPCD2ixAt7jiI2JKWw6Myt2vxvau2O03/U0njuT8LQ/Vl0gE2Lc+BMRXWYO37fQ63SQ3aRyPr98" Sep 01 00:38:46 stefans-speaker go-librespot[22259]: time="2026-09-01T00:38:46+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 00:38:46 stefans-speaker go-librespot[22259]: time="2026-09-01T00:38:46+02:00" level=debug msg="completed keyexchange" Sep 01 00:38:46 stefans-speaker go-librespot[22259]: time="2026-09-01T00:38:46+02:00" level=debug msg="completed challenge" Sep 01 00:38:46 stefans-speaker go-librespot[22259]: time="2026-09-01T00:38:46+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:38:46 stefans-speaker go-librespot[22259]: time="2026-09-01T00:38:46+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:38:46 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:38:46 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:38:46 stefans-speaker volumio[21875]: info: Initializing connection to go-librespot Websocket Sep 01 00:38:46 stefans-speaker volumio[21875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 00:38:48 stefans-speaker volumio[21875]: info: MYVOLUMIO: Adding device Sep 01 00:38:48 stefans-speaker volumio[21875]: info: MYVOLUMIO: Evaluating Server Sep 01 00:38:48 stefans-speaker volumio[21875]: info: Setting Geolocation for MyVolumio to eu2 Sep 01 00:38:48 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:38:48 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:38:48 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:38:48 stefans-speaker volumio[21875]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Sep 01 00:38:49 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Sep 01 00:38:49 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:38:49 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:38:49 stefans-speaker go-librespot[22298]: go-librespot daemon starting... Sep 01 00:38:49 stefans-speaker volumio[21875]: info: Initializing connection to go-librespot Websocket Sep 01 00:38:49 stefans-speaker volumio[21875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 00:38:49 stefans-speaker go-librespot[22299]: time="2026-09-01T00:38:49+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:38:49 stefans-speaker go-librespot[22299]: time="2026-09-01T00:38:49+02:00" level=debug msg="app state loaded" Sep 01 00:38:49 stefans-speaker go-librespot[22299]: time="2026-09-01T00:38:49+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:38:49 stefans-speaker volumio[21875]: info: Updating MyVolumio device info Sep 01 00:38:49 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:38:49 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:38:49 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:38:49 stefans-speaker go-librespot[22299]: time="2026-09-01T00:38: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:38:49 stefans-speaker go-librespot[22299]: time="2026-09-01T00:38: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:38:49 stefans-speaker go-librespot[22299]: time="2026-09-01T00:38: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:38:49 stefans-speaker go-librespot[22299]: time="2026-09-01T00:38:49+02:00" level=info msg="zeroconf server listening on port 44919" Sep 01 00:38:49 stefans-speaker go-librespot[22299]: time="2026-09-01T00:38:49+02:00" level=debug msg="obtained new client token: AAE/h9xsKmFpfGtlGTlKUXSpixE3bYPNfVEQzT4dl691D+tGYXPfCAKXjX22YCN+BqASvircn66udlNrwQOBqQeO12OLaPaUEK7sxMrFwHCnlD6dD/rwSdxsWlvYBY4Q1qpG9zerGCB+l+z0d05GJELY5h+/qnAOseDb9eJjATHecXYIKt7nDed4TWtmTgmM+MYETVImUXIbH0WbUtGi9FSok8K3zi+uCjhFT73u1Zt9+l/cVZazFvL42Ak=" Sep 01 00:38:50 stefans-speaker go-librespot[22299]: time="2026-09-01T00:38:50+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 00:38:50 stefans-speaker go-librespot[22299]: time="2026-09-01T00:38:50+02:00" level=debug msg="completed keyexchange" Sep 01 00:38:50 stefans-speaker go-librespot[22299]: time="2026-09-01T00:38:50+02:00" level=debug msg="completed challenge" Sep 01 00:38:50 stefans-speaker go-librespot[22299]: time="2026-09-01T00:38:50+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:38:50 stefans-speaker go-librespot[22299]: time="2026-09-01T00:38:50+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:38:50 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:38:50 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:38:50 stefans-speaker volumio[21875]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Sep 01 00:38:52 stefans-speaker volumio[21875]: info: Initializing connection to go-librespot Websocket Sep 01 00:38:52 stefans-speaker volumio[21875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 00:38:53 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Sep 01 00:38:53 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:38:53 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:38:53 stefans-speaker go-librespot[22309]: go-librespot daemon starting... Sep 01 00:38:53 stefans-speaker go-librespot[22310]: time="2026-09-01T00:38:53+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:38:53 stefans-speaker go-librespot[22310]: time="2026-09-01T00:38:53+02:00" level=debug msg="app state loaded" Sep 01 00:38:53 stefans-speaker go-librespot[22310]: time="2026-09-01T00:38:53+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:38:53 stefans-speaker go-librespot[22310]: time="2026-09-01T00:38:53+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 00:38:53 stefans-speaker go-librespot[22310]: time="2026-09-01T00:38:53+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:38:53 stefans-speaker go-librespot[22310]: time="2026-09-01T00:38:53+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:38:53 stefans-speaker go-librespot[22310]: time="2026-09-01T00:38:53+02:00" level=info msg="zeroconf server listening on port 40755" Sep 01 00:38:53 stefans-speaker go-librespot[22310]: time="2026-09-01T00:38:53+02:00" level=debug msg="obtained new client token: AAFUprZ/DUP3HlKorR43MqZr0PFMPI4DEWt4HjlWCYIvp9O8tXkCprvzU6DnRw1M4ONI7ZIp2rPZp4x656FFEx1HGWaslAgw+87+WfDJirRyBOu4R6/CkwqBWFb8Fb9vMtdm2ZP5s1JnmvWXRcvjUOI8pMgQdafLoWfBwOUDVYcVDIXWUAB9WuEZGdFRCJFc2FPAIxXKVknTO5f2Ca91jkfMcLPmB3pmxws2qgF+GERNHJXcA4x7p3OMWnE=" Sep 01 00:38:54 stefans-speaker go-librespot[22310]: time="2026-09-01T00:38:54+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 00:38:54 stefans-speaker go-librespot[22310]: time="2026-09-01T00:38:54+02:00" level=debug msg="completed keyexchange" Sep 01 00:38:54 stefans-speaker go-librespot[22310]: time="2026-09-01T00:38:54+02:00" level=debug msg="completed challenge" Sep 01 00:38:54 stefans-speaker go-librespot[22310]: time="2026-09-01T00:38:54+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:38:54 stefans-speaker go-librespot[22310]: time="2026-09-01T00:38:54+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:38:54 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:38:54 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:38:54 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Sep 01 00:38:54 stefans-speaker volumio[21875]: 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:38:54 stefans-speaker volumio[21875]: info: CoreCommandRouter::volumioGetState Sep 01 00:38:54 stefans-speaker volumio[21875]: info: CorePlayQueue::getTrack 0 Sep 01 00:38:55 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 01 00:38:55 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:38:55 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Sep 01 00:38:55 stefans-speaker volumio-remote-updater[679]: Test mode disabled Sep 01 00:38:55 stefans-speaker volumio-remote-updater[679]: Alpha mode disabled Sep 01 00:38:55 stefans-speaker volumio-remote-updater[679]: Alpha legacy test mode disabled Sep 01 00:38:55 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Sep 01 00:38:55 stefans-speaker volumio[21875]: info: Initializing connection to go-librespot Websocket Sep 01 00:38:55 stefans-speaker volumio[21875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 00:38:55 stefans-speaker volumio[21875]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"

FIXES

  • Fix for missing PWM backlight module
  • Fix for crash loop on Onboarding plugin

NEW ADDITIONS

  • Bump RPi/CM4 kernel to 6.12.74

","title":"Update v4.119","updateavailable":true} Sep 01 00:38:55 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Sep 01 00:38:57 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Sep 01 00:38:57 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:38:57 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:38:57 stefans-speaker go-librespot[22323]: go-librespot daemon starting... Sep 01 00:38:57 stefans-speaker go-librespot[22324]: time="2026-09-01T00:38:57+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:38:57 stefans-speaker go-librespot[22324]: time="2026-09-01T00:38:57+02:00" level=debug msg="app state loaded" Sep 01 00:38:57 stefans-speaker go-librespot[22324]: time="2026-09-01T00:38:57+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:38:57 stefans-speaker go-librespot[22324]: time="2026-09-01T00:38:57+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:38:57 stefans-speaker go-librespot[22324]: time="2026-09-01T00:38:57+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:38:57 stefans-speaker go-librespot[22324]: time="2026-09-01T00:38:57+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:38:57 stefans-speaker go-librespot[22324]: time="2026-09-01T00:38:57+02:00" level=info msg="zeroconf server listening on port 43785" Sep 01 00:38:57 stefans-speaker go-librespot[22324]: time="2026-09-01T00:38:57+02:00" level=debug msg="obtained new client token: AAHLth9I76U25rM1/Kg2fjMClPAtROdFpvhgE2RbfxBq4z4cHxrgX9r7sAiq6Ha4okNtX2lYpD1SVI/r4nVwxAuUnfI9UGb01l9+us8EBBd9IN6jn4O2nnrW//zElkNBzydEL5+Qsn5CXbW3PJ5CGoJAArfIn75GdMKccPayFwfPMBPcMi3UFFfVbYHeGG8h+R65GgYw9e5MU9nqLvPdSOGUBhukfaZ4WtC7yUf4lxhsZwRKyDuHBAph6ng=" Sep 01 00:38:57 stefans-speaker go-librespot[22324]: time="2026-09-01T00:38:57+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 00:38:57 stefans-speaker go-librespot[22324]: time="2026-09-01T00:38:57+02:00" level=debug msg="completed keyexchange" Sep 01 00:38:57 stefans-speaker go-librespot[22324]: time="2026-09-01T00:38:57+02:00" level=debug msg="completed challenge" Sep 01 00:38:57 stefans-speaker go-librespot[22324]: time="2026-09-01T00:38:57+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:38:58 stefans-speaker go-librespot[22324]: time="2026-09-01T00:38: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:38:58 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:38:58 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:38:58 stefans-speaker volumio[21875]: info: Initializing connection to go-librespot Websocket Sep 01 00:38:58 stefans-speaker volumio[21875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 00:38:59 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:38:59 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:38:59 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Sep 01 00:38:59 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Sep 01 00:38:59 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Sep 01 00:38:59 stefans-speaker volumio[21875]: info: CoreCommandRouter::volumioGetBrowseSources Sep 01 00:38:59 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 01 00:39:00 stefans-speaker volumio[21875]: error: MyVolumio Plugin failed to authenticate in a timely fashion Sep 01 00:39:00 stefans-speaker volumio[21875]: info: Completed starting MyVolumio Plugin Sep 01 00:39:00 stefans-speaker volumio[21875]: [Metrics] CommandRouter: 44s 183.88ms Sep 01 00:39:00 stefans-speaker volumio[21875]: info: CoreCommandRouter::volumiosetStartupVolume Sep 01 00:39:00 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:39:00 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:39:00 stefans-speaker volumio[21875]: info: CoreCommandRouter::Close All Modals sent Sep 01 00:39:00 stefans-speaker volumio[21875]: info: CoreCommandRouter::Close All Modals sent Sep 01 00:39:01 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Sep 01 00:39:01 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:39:01 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:39:01 stefans-speaker go-librespot[22347]: go-librespot daemon starting... Sep 01 00:39:01 stefans-speaker go-librespot[22348]: time="2026-09-01T00:39:01+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:39:01 stefans-speaker go-librespot[22348]: time="2026-09-01T00:39:01+02:00" level=debug msg="app state loaded" Sep 01 00:39:01 stefans-speaker go-librespot[22348]: time="2026-09-01T00:39:01+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:39:01 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Sep 01 00:39:01 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Sep 01 00:39:01 stefans-speaker volumio[21875]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Sep 01 00:39:01 stefans-speaker go-librespot[22348]: time="2026-09-01T00:39:01+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 00:39:01 stefans-speaker go-librespot[22348]: time="2026-09-01T00:39:01+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:39:01 stefans-speaker go-librespot[22348]: time="2026-09-01T00:39:01+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:39:01 stefans-speaker go-librespot[22348]: time="2026-09-01T00:39:01+02:00" level=info msg="zeroconf server listening on port 40527" Sep 01 00:39:01 stefans-speaker volumio[21875]: info: Initializing connection to go-librespot Websocket Sep 01 00:39:01 stefans-speaker go-librespot[22348]: time="2026-09-01T00:39:01+02:00" level=debug msg="new websocket client" Sep 01 00:39:01 stefans-speaker volumio[21875]: info: Connection to go-librespot Websocket established Sep 01 00:39:01 stefans-speaker go-librespot[22348]: time="2026-09-01T00:39:01+02:00" level=debug msg="obtained new client token: AAGJ3uQUqgX52JoWochTSE/OYmt9WZut1LrbX9+V9tk5xK0Msj50evrYazYvQTp+/HHdeREQgSoQYmFUXj2+RmU8fnCx0QSxoi4ObduVguO/EiNz1YIJN2CYA8zJTE+nf7qJt+3913qB8rYTUSsmNsuXSsjRpdReowNtB8pfZ4FIvRRK6DLHVT5GDXN6JvXg31X1SsQgH4VYkWkf4so5ItjKoyg1v6wtCiU5A9oWGiyQ8USfx4ZKjpvTH1Q=" Sep 01 00:39:01 stefans-speaker go-librespot[22348]: time="2026-09-01T00:39:01+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 00:39:01 stefans-speaker go-librespot[22348]: time="2026-09-01T00:39:01+02:00" level=debug msg="completed keyexchange" Sep 01 00:39:01 stefans-speaker go-librespot[22348]: time="2026-09-01T00:39:01+02:00" level=debug msg="completed challenge" Sep 01 00:39:01 stefans-speaker go-librespot[22348]: time="2026-09-01T00:39:01+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:39:01 stefans-speaker go-librespot[22348]: time="2026-09-01T00:39:01+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:39:02 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:39:02 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:39:02 stefans-speaker volumio[21875]: info: Connection to go-librespot Websocket closed Sep 01 00:39:04 stefans-speaker volumio[21875]: info: Getting Spotify volume Sep 01 00:39:04 stefans-speaker volumio[21875]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 01 00:39:04 stefans-speaker volumio[21875]: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 00:39:04 stefans-speaker volumio[21875]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Sep 01 00:39:04 stefans-speaker volumio[21875]: errno: -111, Sep 01 00:39:04 stefans-speaker volumio[21875]: code: 'ECONNREFUSED', Sep 01 00:39:04 stefans-speaker volumio[21875]: syscall: 'connect', Sep 01 00:39:04 stefans-speaker volumio[21875]: address: '127.0.0.1', Sep 01 00:39:04 stefans-speaker volumio[21875]: port: 9879, Sep 01 00:39:04 stefans-speaker volumio[21875]: response: undefined Sep 01 00:39:04 stefans-speaker volumio[21875]: } Sep 01 00:39:04 stefans-speaker volumio[21875]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 01 00:39:05 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Sep 01 00:39:05 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:39:05 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:39:05 stefans-speaker go-librespot[22371]: go-librespot daemon starting... Sep 01 00:39:05 stefans-speaker go-librespot[22372]: time="2026-09-01T00:39:05+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:39:05 stefans-speaker go-librespot[22372]: time="2026-09-01T00:39:05+02:00" level=debug msg="app state loaded" Sep 01 00:39:05 stefans-speaker go-librespot[22372]: time="2026-09-01T00:39:05+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:39:05 stefans-speaker go-librespot[22372]: time="2026-09-01T00:39:05+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 00:39:05 stefans-speaker go-librespot[22372]: time="2026-09-01T00:39:05+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:39:05 stefans-speaker go-librespot[22372]: time="2026-09-01T00:39:05+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:39:05 stefans-speaker go-librespot[22372]: time="2026-09-01T00:39:05+02:00" level=info msg="zeroconf server listening on port 38953" Sep 01 00:39:05 stefans-speaker go-librespot[22372]: time="2026-09-01T00:39:05+02:00" level=debug msg="obtained new client token: AAEMDTCCXF3mFr3UntEUgh8JuUhb8sHtwUjLVfdEYOQwwQFP+x2haoP2mQxmY2OxVsFrcwOQOZL2K5Qw782Ea0Nlc+L/ZDU/FIjFzt0D2MwEGCY15WsdpTm6g+NV209yi7bCVmz2ykmIMRTB4XOQ3MFfAkQelXEK/SQbO01uyTYq0jdNXaeSKPGXNaf3dCkK2Nvekeb3HJV8JlRjYumdEwcpnnOvwSBOGfQJHgl2f+rbUixK8S0S7MDoJTw=" Sep 01 00:39:05 stefans-speaker sudo[22382]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:39:05 stefans-speaker sudo[22382]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-09-01 00:38' Sep 01 00:39:05 stefans-speaker sudo[22382]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:39:05 stefans-speaker go-librespot[22372]: time="2026-09-01T00:39:05+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 00:39:05 stefans-speaker go-librespot[22372]: time="2026-09-01T00:39:05+02:00" level=debug msg="completed keyexchange" Sep 01 00:39:05 stefans-speaker go-librespot[22372]: time="2026-09-01T00:39:05+02:00" level=debug msg="completed challenge" Sep 01 00:39:05 stefans-speaker go-librespot[22372]: time="2026-09-01T00:39:05+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:39:05 stefans-speaker sudo[22382]: pam_unix(sudo:session): session closed for user root Sep 01 00:39:05 stefans-speaker volumio[21875]: sudo: unable to resolve host stefans-speaker: System error Sep 01 00:39:05 stefans-speaker volumio-remote-updater[679]: [2026-09-01 00:39:05] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Sep 01 00:39:05 stefans-speaker volumio-remote-updater[679]: [2026-09-01 00:39:05] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Sep 01 00:39:05 stefans-speaker systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:39:05 stefans-speaker systemd[1]: volumio.service: Failed with result 'exit-code'. Sep 01 00:39:05 stefans-speaker systemd[1]: volumio.service: Consumed 35.901s CPU time. Sep 01 00:39:05 stefans-speaker go-librespot[22372]: time="2026-09-01T00:39:05+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:39:05 stefans-speaker systemd[1]: Started dynamicswap.service - dynamicswap service. Sep 01 00:39:05 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:39:05 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:39:05 stefans-speaker systemd[1]: dynamicswap.service: Deactivated successfully. Sep 01 00:39:06 stefans-speaker systemd[1]: volumio.service: Scheduled restart job, restart counter is at 251. Sep 01 00:39:06 stefans-speaker systemd[1]: Started dynamicswap.service - dynamicswap service. Sep 01 00:39:06 stefans-speaker systemd[1]: Stopped volumio.service - Volumio Backend Module. Sep 01 00:39:06 stefans-speaker systemd[1]: volumio.service: Consumed 35.901s CPU time. Sep 01 00:39:06 stefans-speaker systemd[1]: Started volumio.service - Volumio Backend Module. Sep 01 00:39:06 stefans-speaker systemd[1]: dynamicswap.service: Deactivated successfully. Sep 01 00:39:08 stefans-speaker volumio[22394]: info: ------------------------------------------- Sep 01 00:39:08 stefans-speaker volumio[22394]: info: ----- Volumio3 ---- Sep 01 00:39:08 stefans-speaker volumio[22394]: info: ------------------------------------------- Sep 01 00:39:08 stefans-speaker volumio[22394]: info: ----- System startup ---- Sep 01 00:39:08 stefans-speaker volumio[22394]: info: ------------------------------------------- Sep 01 00:39:08 stefans-speaker volumio[22394]: info: MYVOLUMIO Environment detected Sep 01 00:39:08 stefans-speaker volumio[22394]: info: Plugin folders cleanup Sep 01 00:39:08 stefans-speaker volumio[22394]: info: Scanning into folder /volumio/app/plugins/ Sep 01 00:39:08 stefans-speaker volumio[22394]: info: Scanning category audio_interface Sep 01 00:39:08 stefans-speaker volumio[22394]: info: Scanning category miscellanea Sep 01 00:39:08 stefans-speaker volumio[22394]: info: Scanning category music_service Sep 01 00:39:08 stefans-speaker volumio[22394]: info: Scanning category plugins.json Sep 01 00:39:08 stefans-speaker volumio[22394]: info: Scanning category system_controller Sep 01 00:39:08 stefans-speaker volumio[22394]: info: Scanning category user_interface Sep 01 00:39:08 stefans-speaker volumio[22394]: info: Scanning into folder /data/plugins/ Sep 01 00:39:08 stefans-speaker volumio[22394]: info: Scanning category music_service Sep 01 00:39:08 stefans-speaker volumio[22394]: info: Plugin folders cleanup completed Sep 01 00:39:08 stefans-speaker volumio[22394]: info: ------------------------------------------- Sep 01 00:39:08 stefans-speaker volumio[22394]: info: ----- Core plugins startup ---- Sep 01 00:39:08 stefans-speaker volumio[22394]: info: ------------------------------------------- Sep 01 00:39:08 stefans-speaker volumio[22394]: info: Loading plugins from folder /volumio/app/plugins/ Sep 01 00:39:08 stefans-speaker volumio[22394]: info: Adding plugin upnp to MyMusic Plugins Sep 01 00:39:08 stefans-speaker volumio[22394]: info: Adding plugin airplay_emulation to MyMusic Plugins Sep 01 00:39:08 stefans-speaker volumio[22394]: info: Adding plugin upnp_browser to MyMusic Plugins Sep 01 00:39:08 stefans-speaker volumio[22394]: info: Loading plugins from folder /data/plugins/ Sep 01 00:39:08 stefans-speaker volumio[22394]: info: Loading plugin "system"... Sep 01 00:39:08 stefans-speaker volumio[22394]: info: Loading plugin "appearance"... Sep 01 00:39:09 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Sep 01 00:39:09 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:39:09 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:39:09 stefans-speaker go-librespot[22421]: go-librespot daemon starting... Sep 01 00:39:09 stefans-speaker go-librespot[22422]: time="2026-09-01T00:39:09+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:39:09 stefans-speaker go-librespot[22422]: time="2026-09-01T00:39:09+02:00" level=debug msg="app state loaded" Sep 01 00:39:09 stefans-speaker go-librespot[22422]: time="2026-09-01T00:39:09+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:39:09 stefans-speaker go-librespot[22422]: time="2026-09-01T00:39: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:39:09 stefans-speaker go-librespot[22422]: time="2026-09-01T00:39: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:39:09 stefans-speaker go-librespot[22422]: time="2026-09-01T00:39: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:39:09 stefans-speaker go-librespot[22422]: time="2026-09-01T00:39:09+02:00" level=info msg="zeroconf server listening on port 45407" Sep 01 00:39:09 stefans-speaker go-librespot[22422]: time="2026-09-01T00:39:09+02:00" level=debug msg="obtained new client token: AAFPqmgtMsEclTXRKLhUePYA+mFYOMl5/j/NAthz//RfU8Sx07n3r87zUcNsEirPwGbbJzFVCfyJVO4R4Ia4Y9Egs7YXy3nedKEWgOyiAvwcgivtScjuxCyAcHhFI5HdBq9vvphR5qR5xkrFsGWKptlWBDbsAHKPMAdimi6+CiWilGu8alk/ZtEYmkaBtpnuxTgaSlj0LIhpJRiF8KUBBF3rRpmpxYO/Q9uKfBeDsVeWvZtI6rFC9Qw+oS8=" Sep 01 00:39:09 stefans-speaker go-librespot[22422]: time="2026-09-01T00:39:09+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 00:39:09 stefans-speaker go-librespot[22422]: time="2026-09-01T00:39:09+02:00" level=debug msg="completed keyexchange" Sep 01 00:39:09 stefans-speaker go-librespot[22422]: time="2026-09-01T00:39:09+02:00" level=debug msg="completed challenge" Sep 01 00:39:09 stefans-speaker go-librespot[22422]: time="2026-09-01T00:39:09+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:39:09 stefans-speaker go-librespot[22422]: time="2026-09-01T00:39:09+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:39:09 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:39:09 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:39:10 stefans-speaker volumio[22394]: info: Loading plugin "network"... Sep 01 00:39:10 stefans-speaker volumio[22394]: info: Refreshing Cached IP Addresses Sep 01 00:39:10 stefans-speaker sudo[22431]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:39:10 stefans-speaker sudo[22433]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:39:10 stefans-speaker volumio[22394]: info: Loading plugin "services"... Sep 01 00:39:10 stefans-speaker sudo[22431]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 01 00:39:10 stefans-speaker volumio[22394]: info: Loading plugin "alsa_controller"... Sep 01 00:39:10 stefans-speaker sudo[22431]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:39:10 stefans-speaker sudo[22433]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 01 00:39:10 stefans-speaker sudo[22440]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:39:10 stefans-speaker sudo[22433]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:39:10 stefans-speaker sudo[22431]: pam_unix(sudo:session): session closed for user root Sep 01 00:39:10 stefans-speaker sudo[22433]: pam_unix(sudo:session): session closed for user root Sep 01 00:39:10 stefans-speaker sudo[22440]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Sep 01 00:39:10 stefans-speaker sudo[22440]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:39:10 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 01 00:39:10 stefans-speaker volumio[22394]: info: Loading plugin "wizard"... Sep 01 00:39:10 stefans-speaker volumio[22394]: info: Loading plugin "networkfs"... Sep 01 00:39:10 stefans-speaker volumio[22394]: info: Starting Udev Watcher for removable devices Sep 01 00:39:10 stefans-speaker volumio[22394]: info: Ignoring mount for partition: boot Sep 01 00:39:10 stefans-speaker volumio[22394]: info: Ignoring mount for partition: volumio Sep 01 00:39:10 stefans-speaker volumio[22394]: info: Ignoring mount for partition: volumio_data Sep 01 00:39:10 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 01 00:39:10 stefans-speaker volumio[22394]: info: Loading plugin "volumio_command_line_client"... Sep 01 00:39:10 stefans-speaker volumio[22394]: info: Loading plugin "upnp"... Sep 01 00:39:10 stefans-speaker volumio[22394]: info: [1788215950386] Starting Upmpd Daemon Sep 01 00:39:10 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 01 00:39:10 stefans-speaker volumio[22394]: info: Loading plugin "my_music"... Sep 01 00:39:10 stefans-speaker volumio[22394]: info: Loading plugin "mpd"... Sep 01 00:39:10 stefans-speaker volumio[22394]: info: Loading plugin "upnp_browser"... Sep 01 00:39:10 stefans-speaker volumio-remote-updater[679]: [2026-09-01 00:39:10] [connect] Successful connection Sep 01 00:39:12 stefans-speaker volumio[22394]: info: Starting UPNP Browser Sep 01 00:39:12 stefans-speaker volumio[22394]: info: Loading plugin "alarm-clock"... Sep 01 00:39:12 stefans-speaker volumio[22394]: info: Loading plugin "airplay_emulation"... Sep 01 00:39:12 stefans-speaker volumio[22394]: info: Starting Shairport Sync Sep 01 00:39:12 stefans-speaker volumio[22394]: info: Loading plugin "last_100"... Sep 01 00:39:12 stefans-speaker volumio[22394]: info: Loading plugin "webradio"... Sep 01 00:39:12 stefans-speaker volumio[22394]: info: Loading plugin "i2s_dacs"... Sep 01 00:39:12 stefans-speaker volumio[22394]: info: I2S DAC not set, start Auto-detection Sep 01 00:39:12 stefans-speaker volumio[22394]: info: Loading plugin "volumiodiscovery"... Sep 01 00:39:12 stefans-speaker volumio[22394]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 01 00:39:12 stefans-speaker volumio[22394]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 01 00:39:12 stefans-speaker volumio[22394]: *** WARNING *** For more information see Sep 01 00:39:12 stefans-speaker volumio[22394]: *** 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:39:12 stefans-speaker volumio[22394]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 01 00:39:12 stefans-speaker volumio[22394]: *** WARNING *** For more information see Sep 01 00:39:12 stefans-speaker node[22394]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 01 00:39:12 stefans-speaker node[22394]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 01 00:39:12 stefans-speaker node[22394]: *** WARNING *** For more information see Sep 01 00:39:12 stefans-speaker node[22394]: *** 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:39:12 stefans-speaker node[22394]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 01 00:39:12 stefans-speaker node[22394]: *** WARNING *** For more information see Sep 01 00:39:12 stefans-speaker volumio[22394]: info: Applying required configuration parameters for plugin volumiodiscovery Sep 01 00:39:12 stefans-speaker volumio[22394]: info: Discovery: Started advertising with name: Stefan’s Speaker Sep 01 00:39:12 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 01 00:39:12 stefans-speaker volumio[22394]: info: Loading plugin "spop"... Sep 01 00:39:13 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Sep 01 00:39:13 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:39:13 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:39:13 stefans-speaker go-librespot[22466]: go-librespot daemon starting... Sep 01 00:39:13 stefans-speaker go-librespot[22470]: time="2026-09-01T00:39:13+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:39:13 stefans-speaker go-librespot[22470]: time="2026-09-01T00:39:13+02:00" level=debug msg="app state loaded" Sep 01 00:39:13 stefans-speaker go-librespot[22470]: time="2026-09-01T00:39:13+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:39:13 stefans-speaker go-librespot[22470]: time="2026-09-01T00:39:13+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 00:39:13 stefans-speaker go-librespot[22470]: time="2026-09-01T00:39:13+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 01 00:39:13 stefans-speaker go-librespot[22470]: time="2026-09-01T00:39:13+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 01 00:39:13 stefans-speaker go-librespot[22470]: time="2026-09-01T00:39:13+02:00" level=info msg="zeroconf server listening on port 41561" Sep 01 00:39:13 stefans-speaker sudo[22440]: pam_unix(sudo:session): session closed for user root Sep 01 00:39:13 stefans-speaker go-librespot[22470]: time="2026-09-01T00:39:13+02:00" level=debug msg="obtained new client token: AAGQdJwPWHmUeUyFaESf2KsEDA/vsgwImYLU7tFMLGR6ktELkveIb8ynlkU0bpHRQtuBCiahFDQmdFY1ZENiF2FZFN2kM7ymmsUiBJVtsijCyOCexOPZpmF1xBR54A/uKsF1ZOyQajXJNBO/DIbHPXplMOwWES8yFAq96YI82RlACJi+obMuYGsc2e2Fa0QJAnkiy9aN5gVJ9hpcJKh2iDCMxapn24Q0OupsIHDNMmSQ+4ZFxTKII94o/EM=" Sep 01 00:39:13 stefans-speaker go-librespot[22470]: time="2026-09-01T00:39:13+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:39:13 stefans-speaker go-librespot[22470]: time="2026-09-01T00:39:13+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Sep 01 00:39:13 stefans-speaker volumio[22394]: info: Loading plugin "ytcr"... Sep 01 00:39:13 stefans-speaker go-librespot[22470]: time="2026-09-01T00:39:13+02:00" level=debug msg="completed keyexchange" Sep 01 00:39:13 stefans-speaker go-librespot[22470]: time="2026-09-01T00:39:13+02:00" level=debug msg="completed challenge" Sep 01 00:39:13 stefans-speaker go-librespot[22470]: time="2026-09-01T00:39:13+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:39:14 stefans-speaker go-librespot[22470]: time="2026-09-01T00:39: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:39:14 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:39:14 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:39:15 stefans-speaker volumio[22394]: info: Loading plugin "outputs"... Sep 01 00:39:15 stefans-speaker volumio[22394]: info: Loading plugin "albumart"... Sep 01 00:39:15 stefans-speaker volumio[22394]: info: Plugin example_plugin is not enabled Sep 01 00:39:15 stefans-speaker volumio[22394]: info: Loading plugin "inputs"... Sep 01 00:39:15 stefans-speaker volumio[22394]: info: Loading plugin "updater_comm"... Sep 01 00:39:15 stefans-speaker volumio[22394]: info: Plugin mpdemulation is not enabled Sep 01 00:39:15 stefans-speaker volumio[22394]: info: Loading plugin "rest_api"... Sep 01 00:39:15 stefans-speaker volumio[22394]: info: Loading plugin "websocket"... Sep 01 00:39:15 stefans-speaker volumio[22394]: info: Starting Socket.io Server version 1.7.4 Sep 01 00:39:15 stefans-speaker volumio[22394]: info: Loading i18n strings for locale nl Sep 01 00:39:15 stefans-speaker volumio[22394]: Updating browse sources language Sep 01 00:39:15 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 00:39:15 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 00:39:15 stefans-speaker volumio[22394]: info: CoreCommandRouter::initPlayerControls Sep 01 00:39:15 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:39:15 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:39:15 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:39:15 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:39:15 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:39:15 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:39:15 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:39:15 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:39:15 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 00:39:15 stefans-speaker volumio[22394]: Express server listening on port 3000 Sep 01 00:39:15 stefans-speaker volumio[22394]: [Metrics] WebUI: 8s 141.40ms Sep 01 00:39:15 stefans-speaker volumio[22394]: info: CoreStateMachine::resetVolumioState Sep 01 00:39:15 stefans-speaker volumio[22394]: info: CoreStateMachine::getcurrentVolume Sep 01 00:39:15 stefans-speaker volumio[22394]: info: CoreCommandRouter::volumioRetrievevolume Sep 01 00:39:15 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:39:15 stefans-speaker volumio[22394]: info: Cannot read play queue from file Sep 01 00:39:15 stefans-speaker volumio[22394]: info: Volumio Network Manager: Network status updated: 2 Sep 01 00:39:15 stefans-speaker volumio[22479]: Forking 3 albumart workers Sep 01 00:39:16 stefans-speaker volumio[22394]: info: VolumeController:: Volume=70 Mute =false Sep 01 00:39:16 stefans-speaker volumio[22394]: info: CoreStateMachine::pushState Sep 01 00:39:16 stefans-speaker volumio[22394]: info: CorePlayQueue::getTrack 0 Sep 01 00:39:16 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 01 00:39:16 stefans-speaker volumio[22394]: info: CoreCommandRouter::volumioPushState Sep 01 00:39:16 stefans-speaker volumio[22394]: info: CoreStateMachine::updateTrackBlock Sep 01 00:39:16 stefans-speaker volumio[22394]: info: CorePlayQueue::getTrackBlock Sep 01 00:39:16 stefans-speaker volumio[22394]: info: CoreCommandRouter::volumioRetrievevolume Sep 01 00:39:16 stefans-speaker volumio[22394]: info: CoreStateMachine::setRepeat null single undefined Sep 01 00:39:16 stefans-speaker volumio[22394]: info: CoreStateMachine::pushState Sep 01 00:39:16 stefans-speaker volumio[22394]: info: CorePlayQueue::getTrack 0 Sep 01 00:39:16 stefans-speaker volumio[22394]: info: CoreCommandRouter::volumioPushState Sep 01 00:39:16 stefans-speaker volumio[22394]: info: CoreStateMachine::setRandom null Sep 01 00:39:16 stefans-speaker volumio[22394]: info: CoreStateMachine::pushState Sep 01 00:39:16 stefans-speaker volumio[22394]: info: CorePlayQueue::getTrack 0 Sep 01 00:39:16 stefans-speaker volumio[22394]: info: CoreCommandRouter::volumioPushState Sep 01 00:39:16 stefans-speaker volumio[22394]: info: Setting Device type: Raspberry PI Sep 01 00:39:16 stefans-speaker volumio[22394]: info: VolumeController:: Volume=70 Mute =false Sep 01 00:39:16 stefans-speaker volumio[22394]: info: CoreStateMachine::pushState Sep 01 00:39:16 stefans-speaker volumio[22394]: info: CorePlayQueue::getTrack 0 Sep 01 00:39:16 stefans-speaker volumio[22394]: info: CoreCommandRouter::volumioPushState Sep 01 00:39:16 stefans-speaker volumio[22394]: info: Completed loading Core Plugins Sep 01 00:39:16 stefans-speaker volumio[22394]: info: Preparing to generate the ALSA configuration file Sep 01 00:39:16 stefans-speaker volumio[22394]: info: Discovery: adding a312d0fa-c0eb-45ad-a25b-79fcdf237e8a Sep 01 00:39:16 stefans-speaker volumio[22394]: info: Discovery: Found device Stefan’s Speaker Sep 01 00:39:16 stefans-speaker volumio[22394]: info: CoreCommandRouter::volumioGetState Sep 01 00:39:16 stefans-speaker volumio[22394]: info: CorePlayQueue::getTrack 0 Sep 01 00:39:16 stefans-speaker volumio[22394]: info: Discovery: this is already registered, a312d0fa-c0eb-45ad-a25b-79fcdf237e8a Sep 01 00:39:16 stefans-speaker volumio[22394]: info: Discovery: Found device Stefan’s Speaker Sep 01 00:39:16 stefans-speaker volumio[22394]: info: CoreCommandRouter::volumioGetState Sep 01 00:39:16 stefans-speaker volumio[22394]: info: CorePlayQueue::getTrack 0 Sep 01 00:39:16 stefans-speaker volumio[22394]: info: Asound.conf file unchanged, so no further update is needed Sep 01 00:39:16 stefans-speaker volumio[22394]: info: Output device has changed, restarting MPD Sep 01 00:39:16 stefans-speaker volumio[22394]: info: Output device has changed, restarting Shairport Sync Sep 01 00:39:16 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:39:16 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:39:16 stefans-speaker sudo[22534]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:39:16 stefans-speaker sudo[22534]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 01 00:39:16 stefans-speaker sudo[22535]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:39:16 stefans-speaker sudo[22534]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:39:16 stefans-speaker volumio[22394]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 01 00:39:16 stefans-speaker volumio[22394]: info: ___________ START PLUGINS ___________ Sep 01 00:39:16 stefans-speaker volumio[22394]: info: ControllerMpd::onStart: Initializing MPD Sep 01 00:39:16 stefans-speaker volumio[22394]: info: Creating MPD Configuration file Sep 01 00:39:16 stefans-speaker sudo[22534]: pam_unix(sudo:session): session closed for user root Sep 01 00:39:16 stefans-speaker sudo[22535]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 01 00:39:16 stefans-speaker sudo[22535]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:39:16 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 00:39:16 stefans-speaker volumio[22394]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 01 00:39:16 stefans-speaker volumio[22394]: info: [1788215956544] CoreMusicLibrary::Adding element Media Servers Sep 01 00:39:16 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 00:39:16 stefans-speaker volumio[22394]: info: UPNP Browser: Client initialized successfully Sep 01 00:39:16 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:39:16 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:39:16 stefans-speaker sudo[22544]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:39:16 stefans-speaker systemd[1]: Stopping mpd.service - Music Player Daemon... Sep 01 00:39:16 stefans-speaker sudo[22545]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:39:16 stefans-speaker volumio[22394]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 01 00:39:16 stefans-speaker sudo[22544]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 01 00:39:16 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:39:16 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:39:16 stefans-speaker sudo[22544]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:39:16 stefans-speaker sudo[22545]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 01 00:39:16 stefans-speaker sudo[22545]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:39:16 stefans-speaker sudo[22544]: pam_unix(sudo:session): session closed for user root Sep 01 00:39:16 stefans-speaker systemd[1]: mpd.service: Deactivated successfully. Sep 01 00:39:16 stefans-speaker systemd[1]: Stopped mpd.service - Music Player Daemon. Sep 01 00:39:16 stefans-speaker systemd[1]: mpd.service: Consumed 4.515s CPU time. Sep 01 00:39:16 stefans-speaker volumio[22394]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 01 00:39:16 stefans-speaker volumio[22394]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 01 00:39:16 stefans-speaker volumio[22394]: info: [1788215956700] CoreMusicLibrary::Adding element Last_100 Sep 01 00:39:16 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 00:39:16 stefans-speaker systemd[1]: mpd.socket: Deactivated successfully. Sep 01 00:39:16 stefans-speaker systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Sep 01 00:39:16 stefans-speaker systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Sep 01 00:39:16 stefans-speaker volumio[22394]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 01 00:39:16 stefans-speaker volumio[22394]: info: [1788215956709] CoreMusicLibrary::Adding element Webradio Sep 01 00:39:16 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 00:39:16 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 01 00:39:16 stefans-speaker volumio[22394]: info: Initializing BBC Radios Sep 01 00:39:16 stefans-speaker systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Sep 01 00:39:16 stefans-speaker systemd[1]: Starting mpd.service - Music Player Daemon... Sep 01 00:39:16 stefans-speaker systemd[1]: mpd.service: Deactivated successfully. Sep 01 00:39:16 stefans-speaker systemd[1]: Stopped mpd.service - Music Player Daemon. Sep 01 00:39:16 stefans-speaker systemd[1]: mpd.socket: Deactivated successfully. Sep 01 00:39:16 stefans-speaker systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Sep 01 00:39:16 stefans-speaker systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Sep 01 00:39:16 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 01 00:39:16 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:39:16 stefans-speaker systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Sep 01 00:39:16 stefans-speaker systemd[1]: Starting mpd.service - Music Player Daemon... Sep 01 00:39:16 stefans-speaker volumio[22394]: info: Creating Spotify config file Sep 01 00:39:16 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:39:17 stefans-speaker sudo[22572]: root : unable to resolve host stefans-speaker: System error Sep 01 00:39:17 stefans-speaker sudo[22572]: sudo: unable to resolve host stefans-speaker: System error Sep 01 00:39:17 stefans-speaker sudo[22572]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Sep 01 00:39:17 stefans-speaker sudo[22572]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Sep 01 00:39:17 stefans-speaker sudo[22572]: pam_unix(sudo:session): session closed for user root Sep 01 00:39:17 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Sep 01 00:39:17 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:39:17 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:39:17 stefans-speaker go-librespot[22576]: go-librespot daemon starting... Sep 01 00:39:17 stefans-speaker go-librespot[22577]: time="2026-09-01T00:39:17+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:39:17 stefans-speaker volumio[22394]: info: Volumio Calling Home Sep 01 00:39:17 stefans-speaker go-librespot[22577]: time="2026-09-01T00:39:17+02:00" level=info msg="zeroconf server listening on port 45297" Sep 01 00:39:17 stefans-speaker volumio[22496]: Starting albumart workers Sep 01 00:39:18 stefans-speaker volumio[22494]: Starting albumart workers Sep 01 00:39:18 stefans-speaker volumio[22394]: info: MPD Permissions set Sep 01 00:39:18 stefans-speaker volumio[22394]: info: MPD Permissions set Sep 01 00:39:18 stefans-speaker volumio[22394]: info: Spotify config file written Sep 01 00:39:18 stefans-speaker sudo[22590]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:39:18 stefans-speaker volumio[22495]: Starting albumart workers Sep 01 00:39:18 stefans-speaker sudo[22590]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Sep 01 00:39:18 stefans-speaker sudo[22590]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:39:18 stefans-speaker systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Sep 01 00:39:18 stefans-speaker systemd[1]: go-librespot-daemon.service: Deactivated successfully. Sep 01 00:39:18 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:39:18 stefans-speaker volumio[22394]: 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:39:18 stefans-speaker volumio[22394]: info: Volumio called home Sep 01 00:39:18 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:39:18 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:39:18 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:39:18 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:39:18 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:39:18 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:39:18 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:39:18 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:39:18 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:39:18 stefans-speaker go-librespot[22592]: go-librespot daemon starting... Sep 01 00:39:18 stefans-speaker sudo[22590]: pam_unix(sudo:session): session closed for user root Sep 01 00:39:18 stefans-speaker go-librespot[22593]: time="2026-09-01T00:39:18+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:39:18 stefans-speaker go-librespot[22593]: time="2026-09-01T00:39:18+02:00" level=debug msg="app state loaded" Sep 01 00:39:18 stefans-speaker go-librespot[22593]: time="2026-09-01T00:39:18+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:39:18 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:39:18 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:39:18 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:39:18 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:39:18 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:39:18 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:39:18 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:39:18 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:39:18 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:39:18 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:39:18 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:39:18 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 00:39:18 stefans-speaker volumio[22394]: info: No need to fix Spotify hosts Sep 01 00:39:18 stefans-speaker go-librespot[22593]: time="2026-09-01T00:39:18+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 00:39:18 stefans-speaker go-librespot[22593]: time="2026-09-01T00:39:18+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:39:18 stefans-speaker go-librespot[22593]: time="2026-09-01T00:39:18+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:39:19 stefans-speaker go-librespot[22593]: time="2026-09-01T00:39:19+02:00" level=info msg="zeroconf server listening on port 44945" Sep 01 00:39:19 stefans-speaker go-librespot[22593]: time="2026-09-01T00:39:19+02:00" level=debug msg="obtained new client token: AAGvh4X2mVqKJnwdNwGlCVxDaDa5mrM6p3Usgc0UWXlFdKO01dw4pPKaO25pAHlSMu6V5fM4WG+3bhtd6SP1anU5qT5X1OGgUpLJ64H728ECOM1MLQ5CwrwPOiICZ5VLb7M41NnneZZoiBiQNxCsKFVafM3zwTqqpQpVSdKN0D82pzbKwIJhufRQdbMMzEDBiYHRMvL3Q//sAgqXELsLDr7ObyKxu7mJu7kbuVr8ohRYioXY4NfoIf5x" Sep 01 00:39:19 stefans-speaker go-librespot[22593]: time="2026-09-01T00:39:19+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:39:19 stefans-speaker go-librespot[22593]: time="2026-09-01T00:39:19+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Sep 01 00:39:19 stefans-speaker go-librespot[22593]: time="2026-09-01T00:39:19+02:00" level=debug msg="completed keyexchange" Sep 01 00:39:19 stefans-speaker go-librespot[22593]: time="2026-09-01T00:39:19+02:00" level=debug msg="completed challenge" Sep 01 00:39:19 stefans-speaker go-librespot[22593]: time="2026-09-01T00:39:19+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:39:19 stefans-speaker go-librespot[22593]: time="2026-09-01T00:39:19+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:39:19 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:39:19 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:39:19 stefans-speaker volumio[22394]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Sep 01 00:39:19 stefans-speaker volumio[22394]: SPOTIFY: BQAm_wOzmy36ljOwog5RZkw9DXR548ODCFelwDFXFCwd7BJEDyrlb5IGzm_RZ2TSjtoy0tEbHxH-uSM4ywVV7kNetxUH0-4fWFWnfRRq_m7aBNiiEpOW4W2nYM1ySvq-51p38LjRSC-hXl7lUvUTJa9griYk7dNqFgVGSv3CvIrKtuDADZJZ3Ds64G1t9D91dIB34l7WizY4neL_GgryWhOfI7uxjejgifZxUlCL2vNeUCUpCUkGXBjAn3S5LYTT3u1aIq3dZff6raEuFJ6p5NvyDb1mLDYwUqYhsO8zInn9VHRJXPi_9vI6kd-oJPc Sep 01 00:39:19 stefans-speaker volumio[22394]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Sep 01 00:39:19 stefans-speaker volumio[22394]: info: New Spotify access token = BQAm_wOzmy36ljOwog5RZkw9DXR548ODCFelwDFXFCwd7BJEDyrlb5IGzm_RZ2TSjtoy0tEbHxH-uSM4ywVV7kNetxUH0-4fWFWnfRRq_m7aBNiiEpOW4W2nYM1ySvq-51p38LjRSC-hXl7lUvUTJa9griYk7dNqFgVGSv3CvIrKtuDADZJZ3Ds64G1t9D91dIB34l7WizY4neL_GgryWhOfI7uxjejgifZxUlCL2vNeUCUpCUkGXBjAn3S5LYTT3u1aIq3dZff6raEuFJ6p5NvyDb1mLDYwUqYhsO8zInn9VHRJXPi_9vI6kd-oJPc Sep 01 00:39:19 stefans-speaker volumio[22394]: info: Spotify credentials grant success - running version from March 24, 2019 Sep 01 00:39:19 stefans-speaker volumio[22394]: info: Starting Shairport Sync Sep 01 00:39:19 stefans-speaker volumio[22394]: info: Starting Shairport Sync Sep 01 00:39:19 stefans-speaker volumio[22394]: info: Starting Shairport Sync Sep 01 00:39:19 stefans-speaker sudo[22629]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:39:19 stefans-speaker sudo[22629]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 01 00:39:19 stefans-speaker sudo[22629]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:39:19 stefans-speaker sudo[22631]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:39:19 stefans-speaker sudo[22631]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 01 00:39:19 stefans-speaker sudo[22631]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:39:19 stefans-speaker sudo[22633]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:39:19 stefans-speaker sudo[22633]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 01 00:39:19 stefans-speaker sudo[22633]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:39:19 stefans-speaker systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Sep 01 00:39:19 stefans-speaker systemd[1]: shairport-sync.service: Deactivated successfully. Sep 01 00:39:19 stefans-speaker systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Sep 01 00:39:19 stefans-speaker systemd[1]: shairport-sync.service: Consumed 1.861s CPU time. Sep 01 00:39:19 stefans-speaker volumio[22394]: info: CoreCommandRouter::volumioGetState Sep 01 00:39:19 stefans-speaker volumio[22394]: info: CorePlayQueue::getTrack 0 Sep 01 00:39:19 stefans-speaker systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Sep 01 00:39:19 stefans-speaker sudo[22631]: pam_unix(sudo:session): session closed for user root Sep 01 00:39:20 stefans-speaker sudo[22633]: pam_unix(sudo:session): session closed for user root Sep 01 00:39:20 stefans-speaker sudo[22629]: pam_unix(sudo:session): session closed for user root Sep 01 00:39:20 stefans-speaker volumio[22394]: info: Shairport-Sync Started Sep 01 00:39:20 stefans-speaker volumio[22394]: Error adding Membership: Error: addMembership EINVAL Sep 01 00:39:20 stefans-speaker volumio[22394]: info: Shairport-Sync Started Sep 01 00:39:20 stefans-speaker volumio[22394]: info: Shairport-Sync Started Sep 01 00:39:20 stefans-speaker volumio[22394]: 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:39:20 stefans-speaker volumio[22394]: info: Spotify Successfully logged in Sep 01 00:39:20 stefans-speaker volumio[22394]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 01 00:39:20 stefans-speaker volumio[22394]: info: [1788215960053] CoreMusicLibrary::Adding element Spotify Sep 01 00:39:20 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 00:39:20 stefans-speaker volumio[22394]: Cannot find translation for source Spotify Sep 01 00:39:20 stefans-speaker volumio[22394]: info: [yt-cast-receiver] DIAL server listening on port 8098 Sep 01 00:39:20 stefans-speaker volumio[22394]: info: CoreCommandRouter::volumioRetrievevolume Sep 01 00:39:20 stefans-speaker sudo[22668]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:39:20 stefans-speaker sudo[22668]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 01 00:39:20 stefans-speaker sudo[22668]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:39:20 stefans-speaker sudo[22670]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:39:20 stefans-speaker sudo[22668]: pam_unix(sudo:session): session closed for user root Sep 01 00:39:20 stefans-speaker sudo[22670]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 01 00:39:20 stefans-speaker sudo[22670]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:39:20 stefans-speaker sudo[22670]: pam_unix(sudo:session): session closed for user root Sep 01 00:39:20 stefans-speaker volumio[22394]: info: VolumeController:: Volume=70 Mute =false Sep 01 00:39:20 stefans-speaker volumio[22394]: info: CoreCommandRouter::volumioGetState Sep 01 00:39:20 stefans-speaker volumio[22394]: info: CorePlayQueue::getTrack 0 Sep 01 00:39:20 stefans-speaker volumio[22394]: info: CoreStateMachine::pushState Sep 01 00:39:20 stefans-speaker volumio[22394]: info: CorePlayQueue::getTrack 0 Sep 01 00:39:20 stefans-speaker volumio[22394]: info: CoreCommandRouter::volumioPushState Sep 01 00:39:20 stefans-speaker sudo[22675]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:39:20 stefans-speaker sudo[22675]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Sep 01 00:39:20 stefans-speaker sudo[22675]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:39:20 stefans-speaker sudo[22675]: pam_unix(sudo:session): session closed for user root Sep 01 00:39:20 stefans-speaker volumio[22394]: info: Upmpdcli Daemon Started Sep 01 00:39:21 stefans-speaker mpd[22575]: 2026-09-01T00:39:21 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Sep 01 00:39:21 stefans-speaker systemd[1]: Started mpd.service - Music Player Daemon. Sep 01 00:39:21 stefans-speaker sudo[22535]: pam_unix(sudo:session): session closed for user root Sep 01 00:39:21 stefans-speaker sudo[22545]: pam_unix(sudo:session): session closed for user root Sep 01 00:39:21 stefans-speaker volumio[22394]: error: MPD error: The expression evaluated to a falsy value: Sep 01 00:39:21 stefans-speaker volumio[22394]: assert.ok(self.idling) Sep 01 00:39:21 stefans-speaker volumio[22394]: error: The expression evaluated to a falsy value: Sep 01 00:39:21 stefans-speaker volumio[22394]: assert.ok(self.idling) Sep 01 00:39:21 stefans-speaker volumio[22394]: info: MPD running with PID22575 Sep 01 00:39:21 stefans-speaker volumio[22394]: ,establishing connection Sep 01 00:39:21 stefans-speaker volumio[22394]: error: updateQueue error: null Sep 01 00:39:21 stefans-speaker volumio[22394]: info: Completed starting Core Plugins Sep 01 00:39:21 stefans-speaker volumio[22394]: info: ------------------------------------------- Sep 01 00:39:21 stefans-speaker volumio[22394]: info: ----- MyVolumio plugins startup ---- Sep 01 00:39:21 stefans-speaker volumio[22394]: info: ------------------------------------------- Sep 01 00:39:21 stefans-speaker volumio[22394]: info: [MyVolumio PluginManager] Fetching plans data.... Sep 01 00:39:21 stefans-speaker volumio[22394]: error: updateQueue error: null Sep 01 00:39:22 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Sep 01 00:39:22 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:39:22 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:39:22 stefans-speaker go-librespot[22683]: go-librespot daemon starting... Sep 01 00:39:22 stefans-speaker go-librespot[22684]: time="2026-09-01T00:39:22+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:39:22 stefans-speaker go-librespot[22684]: time="2026-09-01T00:39:22+02:00" level=debug msg="app state loaded" Sep 01 00:39:22 stefans-speaker go-librespot[22684]: time="2026-09-01T00:39:22+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:39:22 stefans-speaker volumio[22394]: info: go-librespot daemon successfully initialized Sep 01 00:39:22 stefans-speaker go-librespot[22684]: time="2026-09-01T00:39:22+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 00:39:22 stefans-speaker go-librespot[22684]: time="2026-09-01T00:39:22+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:39:22 stefans-speaker go-librespot[22684]: time="2026-09-01T00:39:22+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:39:22 stefans-speaker go-librespot[22684]: time="2026-09-01T00:39:22+02:00" level=info msg="zeroconf server listening on port 46131" Sep 01 00:39:22 stefans-speaker go-librespot[22684]: time="2026-09-01T00:39:22+02:00" level=debug msg="obtained new client token: AAF2DpyMJiPVEawzGLs3KhlqBjYGpoXuuJU27c5IHR+1xGF5mzltNjFACdgqTnBavw4TfLlsrVP46bpELAAGMtdQa23P0oVY9wJaaor/SXGDhWGo501zs1FxPGrwlBztQzh7R33aTqiNiYvHazXC+OEkO18cFavSk/5s/0J9pQ9hsPjTpwK0HhsMNqjWvzc0+y+ie+y8F6IUOx4x1OCjHqlRvdPPcm2VlaNCwlU0OjX50gPHkpgJuQE8CgI=" Sep 01 00:39:23 stefans-speaker go-librespot[22684]: time="2026-09-01T00:39:23+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 00:39:23 stefans-speaker volumio-remote-updater[679]: [2026-09-01 00:39:23] [connect] Successful connection Sep 01 00:39:23 stefans-speaker volumio-remote-updater[679]: [2026-09-01 00:39:23] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1788215963 101 Sep 01 00:39:23 stefans-speaker volumio[22394]: 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:39:24 stefans-speaker go-librespot[22684]: time="2026-09-01T00:39:24+02:00" level=debug msg="completed keyexchange" Sep 01 00:39:24 stefans-speaker go-librespot[22684]: time="2026-09-01T00:39:24+02:00" level=debug msg="completed challenge" Sep 01 00:39:24 stefans-speaker sudo[22694]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:39:24 stefans-speaker sudo[22694]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Sep 01 00:39:24 stefans-speaker sudo[22694]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:39:24 stefans-speaker go-librespot[22684]: time="2026-09-01T00:39:24+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:39:24 stefans-speaker sudo[22696]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:39:24 stefans-speaker sudo[22696]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Sep 01 00:39:24 stefans-speaker sudo[22696]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:39:24 stefans-speaker systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Sep 01 00:39:24 stefans-speaker systemd[1]: mpd_monitor.service: Deactivated successfully. Sep 01 00:39:24 stefans-speaker systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Sep 01 00:39:24 stefans-speaker systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Sep 01 00:39:24 stefans-speaker sudo[22696]: pam_unix(sudo:session): session closed for user root Sep 01 00:39:24 stefans-speaker sudo[22694]: pam_unix(sudo:session): session closed for user root Sep 01 00:39:24 stefans-speaker volumio[22394]: info: Successfully started MPD Monitor Sep 01 00:39:24 stefans-speaker mpd_monitor.sh[22699]: MPD Monitor Service: Starting MPD Monitor Service Sep 01 00:39:24 stefans-speaker volumio[22394]: info: Successfully started MPD Monitor Sep 01 00:39:24 stefans-speaker go-librespot[22684]: time="2026-09-01T00:39: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:39:24 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:39:24 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:39:25 stefans-speaker volumio[22394]: info: Initializing connection to go-librespot Websocket Sep 01 00:39:25 stefans-speaker volumio[22394]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 00:39:26 stefans-speaker volumio[22394]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Sep 01 00:39:28 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Sep 01 00:39:28 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:39:28 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:39:28 stefans-speaker go-librespot[22703]: go-librespot daemon starting... Sep 01 00:39:28 stefans-speaker go-librespot[22704]: time="2026-09-01T00:39:28+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:39:28 stefans-speaker go-librespot[22704]: time="2026-09-01T00:39:28+02:00" level=debug msg="app state loaded" Sep 01 00:39:28 stefans-speaker go-librespot[22704]: time="2026-09-01T00:39:28+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:39:28 stefans-speaker go-librespot[22704]: time="2026-09-01T00:39:28+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 00:39:28 stefans-speaker go-librespot[22704]: time="2026-09-01T00:39:28+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 01 00:39:28 stefans-speaker go-librespot[22704]: time="2026-09-01T00:39:28+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 01 00:39:28 stefans-speaker go-librespot[22704]: time="2026-09-01T00:39:28+02:00" level=info msg="zeroconf server listening on port 34795" Sep 01 00:39:28 stefans-speaker go-librespot[22704]: time="2026-09-01T00:39:28+02:00" level=debug msg="obtained new client token: AAFywk4eD4TPA0X3+Q0ZMTcsikNNXOmkc33R4O58gAQx3qaz+a7KBaZPDPDVDCVLibiP6BflXr/sEwfMYvI6PfVAyDa44oxhY2ktGdDNamEZHBFpwO/2PD1ab/rLo6dKOgf3yJSohch0JAa+GH4LxT0xo8KWaX1JAY3FXeN47Xtf9i5Fbmww4AxyR3SJTbqYN5nIOzEFJo6Cso0gr45I2eN0knQEMGqiMqJlL3DZE96ODQpts+vD9WCR9wU=" Sep 01 00:39:28 stefans-speaker go-librespot[22704]: time="2026-09-01T00:39:28+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 00:39:28 stefans-speaker go-librespot[22704]: time="2026-09-01T00:39:28+02:00" level=debug msg="completed keyexchange" Sep 01 00:39:28 stefans-speaker go-librespot[22704]: time="2026-09-01T00:39:28+02:00" level=debug msg="completed challenge" Sep 01 00:39:28 stefans-speaker volumio[22394]: info: Initializing connection to go-librespot Websocket Sep 01 00:39:28 stefans-speaker go-librespot[22704]: time="2026-09-01T00:39:28+02:00" level=debug msg="new websocket client" Sep 01 00:39:28 stefans-speaker volumio[22394]: info: Connection to go-librespot Websocket established Sep 01 00:39:28 stefans-speaker go-librespot[22704]: time="2026-09-01T00:39:28+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:39:28 stefans-speaker go-librespot[22704]: time="2026-09-01T00:39:28+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:39:28 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:39:28 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:39:28 stefans-speaker volumio[22394]: info: Connection to go-librespot Websocket closed Sep 01 00:39:30 stefans-speaker volumio[22394]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Sep 01 00:39:30 stefans-speaker volumio[22394]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Sep 01 00:39:30 stefans-speaker volumio[22394]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Sep 01 00:39:30 stefans-speaker volumio[22394]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Sep 01 00:39:30 stefans-speaker volumio[22394]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Sep 01 00:39:30 stefans-speaker volumio[22394]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Sep 01 00:39:30 stefans-speaker volumio[22394]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Sep 01 00:39:30 stefans-speaker volumio[22394]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Sep 01 00:39:30 stefans-speaker volumio[22394]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Sep 01 00:39:30 stefans-speaker volumio[22394]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Sep 01 00:39:30 stefans-speaker volumio[22394]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Sep 01 00:39:30 stefans-speaker volumio[22394]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Sep 01 00:39:30 stefans-speaker volumio[22394]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Sep 01 00:39:30 stefans-speaker volumio[22394]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Sep 01 00:39:30 stefans-speaker volumio[22394]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Sep 01 00:39:30 stefans-speaker volumio[22394]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Sep 01 00:39:30 stefans-speaker volumio[22394]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Sep 01 00:39:30 stefans-speaker volumio[22394]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Sep 01 00:39:30 stefans-speaker volumio[22394]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Sep 01 00:39:30 stefans-speaker volumio[22394]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Sep 01 00:39:30 stefans-speaker volumio[22394]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Sep 01 00:39:30 stefans-speaker volumio[22394]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Sep 01 00:39:30 stefans-speaker volumio[22394]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Sep 01 00:39:30 stefans-speaker volumio[22394]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Sep 01 00:39:30 stefans-speaker volumio[22394]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Sep 01 00:39:30 stefans-speaker volumio[22394]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Sep 01 00:39:30 stefans-speaker volumio[22394]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Sep 01 00:39:30 stefans-speaker volumio[22394]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Sep 01 00:39:30 stefans-speaker volumio[22394]: info: Adding plugin bluetooth to MyMusic Plugins Sep 01 00:39:30 stefans-speaker volumio[22394]: info: Adding plugin multiroom to MyMusic Plugins Sep 01 00:39:30 stefans-speaker volumio[22394]: info: Adding plugin metavolumio to MyMusic Plugins Sep 01 00:39:30 stefans-speaker volumio[22394]: info: Adding plugin cd_controller to MyMusic Plugins Sep 01 00:39:30 stefans-speaker volumio[22394]: info: Adding plugin qobuzconnect to MyMusic Plugins Sep 01 00:39:30 stefans-speaker volumio[22394]: info: Adding plugin smart_inputs to MyMusic Plugins Sep 01 00:39:30 stefans-speaker volumio[22394]: info: Adding plugin tidalconnect to MyMusic Plugins Sep 01 00:39:30 stefans-speaker volumio[22394]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Sep 01 00:39:31 stefans-speaker volumio[22394]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Sep 01 00:39:31 stefans-speaker volumio[22394]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Sep 01 00:39:31 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:39:31 stefans-speaker volumio[22394]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 00:39:31 stefans-speaker volumio[22394]: info: Starting MyVolumio Remote Streaming Endpoints Sep 01 00:39:31 stefans-speaker volumio[22394]: info: MyVolumio login type: Token Sep 01 00:39:31 stefans-speaker volumio[22394]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Sep 01 00:39:31 stefans-speaker volumio[22394]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Sep 01 00:39:32 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Sep 01 00:39:32 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:39:32 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Sep 01 00:39:32 stefans-speaker go-librespot[22725]: go-librespot daemon starting... Sep 01 00:39:32 stefans-speaker go-librespot[22726]: time="2026-09-01T00:39:32+02:00" level=info msg="running go-librespot 0.4.0" Sep 01 00:39:32 stefans-speaker go-librespot[22726]: time="2026-09-01T00:39:32+02:00" level=debug msg="app state loaded" Sep 01 00:39:32 stefans-speaker go-librespot[22726]: time="2026-09-01T00:39:32+02:00" level=info msg="api server listening on 127.0.0.1:9879" Sep 01 00:39:32 stefans-speaker volumio[22394]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Sep 01 00:39:32 stefans-speaker volumio[22394]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Sep 01 00:39:32 stefans-speaker volumio[22394]: info: Streaming services startup Sep 01 00:39:32 stefans-speaker volumio[22394]: info: Starting Streaming Daemon Sep 01 00:39:32 stefans-speaker volumio[22394]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Sep 01 00:39:32 stefans-speaker sudo[22735]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:39:32 stefans-speaker sudo[22735]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Sep 01 00:39:32 stefans-speaker sudo[22735]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 00:39:32 stefans-speaker go-librespot[22726]: time="2026-09-01T00:39:32+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 01 00:39:32 stefans-speaker go-librespot[22726]: time="2026-09-01T00:39:32+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:39:32 stefans-speaker go-librespot[22726]: time="2026-09-01T00:39:32+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:39:32 stefans-speaker sudo[22735]: pam_unix(sudo:session): session closed for user root Sep 01 00:39:32 stefans-speaker go-librespot[22726]: time="2026-09-01T00:39:32+02:00" level=info msg="zeroconf server listening on port 45607" Sep 01 00:39:32 stefans-speaker volumio[22394]: info: Getting Spotify volume Sep 01 00:39:32 stefans-speaker volumio[22394]: info: Initializing connection to go-librespot Websocket Sep 01 00:39:32 stefans-speaker volumio[22394]: error: Cannot start Volumio Streaming Daemon Sep 01 00:39:32 stefans-speaker volumio[22394]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Sep 01 00:39:32 stefans-speaker volumio[22394]: sudo: unable to resolve host stefans-speaker: System error Sep 01 00:39:32 stefans-speaker volumio[22394]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Sep 01 00:39:32 stefans-speaker go-librespot[22726]: time="2026-09-01T00:39:32+02:00" level=debug msg="new websocket client" Sep 01 00:39:32 stefans-speaker volumio[22394]: 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:39:32 stefans-speaker volumio[22394]: info: Connection to go-librespot Websocket established Sep 01 00:39:32 stefans-speaker go-librespot[22726]: time="2026-09-01T00:39:32+02:00" level=debug msg="obtained new client token: AAFVLkiWKXUdKh7ouhiiYvBSHzb7I2ocTFQhN70saZvEUgEXdSIrwEFVPzQnOmM6TfK56KCt9h52twRtg+mC6M/0jZMPxE0rKd3AxxG3S8wVt+o7HjbYSBz5cdJmbzGa/yFpe1sElmMH+VQIBhlVIXhkIMZEFVes8G42OeRbP3LuWxr1rVdyze+Ygao54sMW1gEHJuwKzDt8nn74+Y2nL7yEFWyFG/FEeXu/cfiPU0vKMB5Rp3tWjrQcUzw=" Sep 01 00:39:32 stefans-speaker go-librespot[22726]: time="2026-09-01T00:39:32+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Sep 01 00:39:32 stefans-speaker volumio[22394]: info: CoreCommandRouter::volumioGetState Sep 01 00:39:32 stefans-speaker volumio[22394]: info: CorePlayQueue::getTrack 0 Sep 01 00:39:32 stefans-speaker volumio[22394]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 Sep 01 00:39:32 stefans-speaker volumio[22394]: SPOTIFY: SPOTIFY VOLUME undefined Sep 01 00:39:32 stefans-speaker volumio[22394]: SPOTIFY: VOLUMIO VOLUME 70 Sep 01 00:39:32 stefans-speaker volumio[22394]: info: Aligning Spotify Volume to Volumio Volume Sep 01 00:39:32 stefans-speaker volumio[22394]: info: CoreCommandRouter::volumioGetState Sep 01 00:39:32 stefans-speaker volumio[22394]: info: CorePlayQueue::getTrack 0 Sep 01 00:39:32 stefans-speaker volumio[22394]: info: Setting Spotify Volume from Volumio: 70 Sep 01 00:39:32 stefans-speaker go-librespot[22726]: time="2026-09-01T00:39:32+02:00" level=debug msg="completed keyexchange" Sep 01 00:39:32 stefans-speaker go-librespot[22726]: time="2026-09-01T00:39:32+02:00" level=debug msg="completed challenge" Sep 01 00:39:32 stefans-speaker go-librespot[22726]: time="2026-09-01T00:39:32+02:00" level=info msg="authenticated AP" username="31************************cy" Sep 01 00:39:32 stefans-speaker go-librespot[22726]: time="2026-09-01T00:39:32+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:39:32 stefans-speaker volumio[22394]: info: Connection to go-librespot Websocket closed Sep 01 00:39:32 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 00:39:32 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 00:39:32 stefans-speaker volumio[22394]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 01 00:39:32 stefans-speaker volumio[22394]: Error: socket hang up Sep 01 00:39:32 stefans-speaker volumio[22394]: at connResetException (node:internal/errors:720:14) Sep 01 00:39:32 stefans-speaker volumio[22394]: at Socket.socketOnEnd (node:_http_client:519:23) Sep 01 00:39:32 stefans-speaker volumio[22394]: at Socket.emit (node:events:526:35) Sep 01 00:39:32 stefans-speaker volumio[22394]: at endReadableNT (node:internal/streams/readable:1376:12) Sep 01 00:39:32 stefans-speaker volumio[22394]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Sep 01 00:39:32 stefans-speaker volumio[22394]: code: 'ECONNRESET', Sep 01 00:39:32 stefans-speaker volumio[22394]: response: undefined Sep 01 00:39:32 stefans-speaker volumio[22394]: } Sep 01 00:39:32 stefans-speaker volumio[22394]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 01 00:39:33 stefans-speaker sudo[22755]: volumio : unable to resolve host stefans-speaker: System error Sep 01 00:39:33 stefans-speaker sudo[22755]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-09-01 00:38' Sep 01 00:39:33 stefans-speaker sudo[22755]: 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"