Oct 12 12:12:00 muziekspeler systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Oct 12 12:12:00 muziekspeler systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 12:12:00 muziekspeler systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 12:12:00 muziekspeler go-librespot[2204]: go-librespot daemon starting... Oct 12 12:12:00 muziekspeler go-librespot[2205]: time="2026-10-12T12:12:00+02:00" level=info msg="running go-librespot 0.7.1" Oct 12 12:12:00 muziekspeler go-librespot[2205]: time="2026-10-12T12:12:00+02:00" level=debug msg="app state loaded" Oct 12 12:12:01 muziekspeler go-librespot[2205]: time="2026-10-12T12:12:01+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 12:12:01 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:01.080+02:00 level=ERROR msg="failed to notify all device data" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.1.240:43056 @ 0x25ff0e0" latency=-1.383132974s timeout=20s error="failed to get system info: could not get system info: context deadline exceeded" Oct 12 12:12:01 muziekspeler volumio[1200]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Oct 12 12:12:01 muziekspeler go-librespot[2205]: time="2026-10-12T12:12: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 12 12:12:01 muziekspeler go-librespot[2205]: time="2026-10-12T12:12:01+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 12 12:12:01 muziekspeler go-librespot[2205]: time="2026-10-12T12:12:01+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 12 12:12:01 muziekspeler volumio[1200]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Oct 12 12:12:01 muziekspeler volumio[1200]: info: Streaming services startup Oct 12 12:12:01 muziekspeler go-librespot[2205]: time="2026-10-12T12:12:01+02:00" level=info msg="zeroconf server listening on port 40455" Oct 12 12:12:01 muziekspeler go-librespot[2205]: time="2026-10-12T12:12:01+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Oct 12 12:12:01 muziekspeler volumio[1200]: info: Starting Streaming Daemon Oct 12 12:12:01 muziekspeler go-librespot[2205]: time="2026-10-12T12:12:01+02:00" level=debug msg="obtained new client token: AAFWjKwh4g1w5JHP3SrnnMizf8gHTWHaKZ775Ny37FvQSQLiDJgPS8m4cdMuRC7ytIgHL/ze1J0rM2XkosTKgAheeIx4WckZlmC2kQ/exlJEDVNgIxW7DoxvYvDAN8HL99MEGla4bAP4PQuGOwuWgXMVymfnY/o1z3AkS+4+PoXGYwlC59wfzt/sgtwbJyXVdad5uCRQ0gKmpigQIwdWdmSXDjo/tWUlVAO1Xu4yVYEmAF7CcqePDRn0hw==" Oct 12 12:12:01 muziekspeler go-librespot[2205]: time="2026-10-12T12:12:01+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Oct 12 12:12:01 muziekspeler go-librespot[2205]: time="2026-10-12T12:12:01+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Oct 12 12:12:02 muziekspeler volumio[1200]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Oct 12 12:12:02 muziekspeler go-librespot[2205]: time="2026-10-12T12:12:02+02:00" level=debug msg="completed keyexchange" Oct 12 12:12:02 muziekspeler go-librespot[2205]: time="2026-10-12T12:12:02+02:00" level=debug msg="completed challenge" Oct 12 12:12:02 muziekspeler go-librespot[2205]: time="2026-10-12T12:12:02+02:00" level=info msg="authenticated AP" username="do**ey" Oct 12 12:12:02 muziekspeler go-librespot[2205]: time="2026-10-12T12:12:02+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 12:12:02 muziekspeler systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 12:12:02 muziekspeler systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 12:12:02 muziekspeler volumio[1200]: info: Initializing connection to go-librespot Websocket Oct 12 12:12:02 muziekspeler sudo[2215]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 12 12:12:02 muziekspeler sudo[2215]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 12:12:03 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 12 12:12:03 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 12:12:03 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 12 12:12:03 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 12 12:12:03 muziekspeler volumio[1200]: info: Received Get System Info Oct 12 12:12:03 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 12 12:12:03 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 12 12:12:03 muziekspeler volumio[1200]: info: Discovery: Getting this device information Oct 12 12:12:03 muziekspeler volumio[1200]: info: CoreCommandRouter::volumioGetState Oct 12 12:12:03 muziekspeler volumio[1200]: info: CorePlayQueue::getTrack 0 Oct 12 12:12:03 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 12 12:12:03 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 12 12:12:03 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 12 12:12:03 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:03.717+02:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.1.240:43056,00:00:00:00:00:00%01 @ 0x25ff0e0" latency=-1.453896784s timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_SETUP_V1_INTERNET Oct 12 12:12:03 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:03.730+02:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.1.240:43056,00:00:00:00:00:00%01 @ 0x25ff0e0" latency=-1.444733189s timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Oct 12 12:12:03 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 12 12:12:03 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 12 12:12:03 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 12 12:12:03 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:03.751+02:00 level=INFO msg="run WiFi scan" component=server type=REQUEST_TYPE_RUN_WIFI_SCAN peer="192.168.1.240:43056,00:00:00:00:00:00%01 @ 0x25ff0e0" latency=-1.460649857s timeout=1m0s Oct 12 12:12:03 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 12 12:12:03 muziekspeler sudo[2215]: pam_unix(sudo:session): session closed for user root Oct 12 12:12:03 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:03.787+02:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.240:43056,00:00:00:00:00:00%01 @ 0x25ff0e0" latency=-1.444991211s timeout=10s Oct 12 12:12:04 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:04.069+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.240:43056,00:00:00:00:00:00%01 @ 0x25ff0e0" latency=-1.444991211s timeout=10s endpoint=http://pushupdates.volumio.org duration=269.143698ms Oct 12 12:12:04 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:04.579+02:00 level=INFO msg="emitting wifi scan event" component=server peer="192.168.1.240:43056,00:00:00:00:00:00%01 @ 0x25ff0e0" networks=5 Oct 12 12:12:04 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:04.652+02:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.240:43056,00:00:00:00:00:00%01 @ 0x25ff0e0" latency=-1.444991211s timeout=10s endpoint=http://cddb.volumio.org duration=851.721354ms error="Head \"http://gnudb.gnudb.org/~cddb/cddb.cgi/\": EOF" Oct 12 12:12:04 muziekspeler volumio[1200]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 12:12:04 muziekspeler volumio[1200]: error: Cannot start Volumio Streaming Daemon Oct 12 12:12:04 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:04.831+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.240:43056,00:00:00:00:00:00%01 @ 0x25ff0e0" latency=-1.444991211s timeout=10s endpoint=http://plugins.volumio.org duration=1.031209426s Oct 12 12:12:04 muziekspeler volumio[1200]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 12 12:12:04 muziekspeler volumio[1200]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 12 12:12:05 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:05.187+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.240:43056,00:00:00:00:00:00%01 @ 0x25ff0e0" latency=-1.444991211s timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=1.399916718s Oct 12 12:12:05 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:05.197+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.240:43056,00:00:00:00:00:00%01 @ 0x25ff0e0" latency=-1.444991211s timeout=10s endpoint=https://myvolumio.firebaseio.com duration=1.397286875s Oct 12 12:12:05 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:05.203+02:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.1.240:43056,00:00:00:00:00:00%01 @ 0x25ff0e0" available=true connected=true macAddress=b8:27:eb:b7:0a:c4 ip4Address=192.168.1.77/24 ip6Address= ssid=Potgieterlaan_2.4G Oct 12 12:12:05 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:05.242+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.240:43056,00:00:00:00:00:00%01 @ 0x25ff0e0" latency=-1.444991211s timeout=10s endpoint=https://www.googleapis.com duration=1.421057604s Oct 12 12:12:05 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:05.378+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.240:43056,00:00:00:00:00:00%01 @ 0x25ff0e0" latency=-1.444991211s timeout=10s endpoint=https://securetoken.googleapis.com duration=1.587451979s Oct 12 12:12:05 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:05.430+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.240:43056,00:00:00:00:00:00%01 @ 0x25ff0e0" latency=-1.444991211s timeout=10s endpoint=https://google.com duration=1.629985677s Oct 12 12:12:05 muziekspeler systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Oct 12 12:12:05 muziekspeler systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 12:12:05 muziekspeler volumio[1200]: SPOTIFY: User informations: {"account_id":"ToLIjQjGlo","country":"NL","display_name":"douwey","email":"dwayska@hotmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/douwey"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/douwey","id":"douwey","images":[],"product":"premium","type":"user","uri":"spotify:user:douwey"} Oct 12 12:12:05 muziekspeler volumio[1200]: info: Spotify Successfully logged in Oct 12 12:12:05 muziekspeler volumio[1200]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 12 12:12:05 muziekspeler volumio[1200]: info: [1791799925618] CoreMusicLibrary::Adding element Spotify Oct 12 12:12:05 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 12:12:05 muziekspeler systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 12:12:05 muziekspeler go-librespot[2234]: go-librespot daemon starting... Oct 12 12:12:05 muziekspeler volumio[1200]: Cannot find translation for source Spotify Oct 12 12:12:05 muziekspeler go-librespot[2235]: time="2026-10-12T12:12:05+02:00" level=info msg="running go-librespot 0.7.1" Oct 12 12:12:05 muziekspeler go-librespot[2235]: time="2026-10-12T12:12:05+02:00" level=debug msg="app state loaded" Oct 12 12:12:05 muziekspeler go-librespot[2235]: time="2026-10-12T12:12:05+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 12:12:06 muziekspeler go-librespot[2235]: time="2026-10-12T12:12:06+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 12 12:12:06 muziekspeler go-librespot[2235]: time="2026-10-12T12:12:06+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 12 12:12:06 muziekspeler go-librespot[2235]: time="2026-10-12T12:12:06+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 12 12:12:06 muziekspeler go-librespot[2235]: time="2026-10-12T12:12:06+02:00" level=info msg="zeroconf server listening on port 39725" Oct 12 12:12:06 muziekspeler go-librespot[2235]: time="2026-10-12T12:12:06+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Oct 12 12:12:06 muziekspeler volumio[1200]: info: Received Get System Info Oct 12 12:12:06 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 12 12:12:06 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 12 12:12:06 muziekspeler volumio[1200]: info: Discovery: Getting this device information Oct 12 12:12:06 muziekspeler volumio[1200]: info: CoreCommandRouter::volumioGetState Oct 12 12:12:06 muziekspeler volumio[1200]: info: CorePlayQueue::getTrack 0 Oct 12 12:12:06 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 12 12:12:07 muziekspeler go-librespot[2235]: time="2026-10-12T12:12:07+02:00" level=debug msg="obtained new client token: AAGpXv2eAx9/qYaR8bL3WWMWELh+AvXAoRnKfM0C49Ht+uzLa5c9EaV8h2WZxKA68sUeTSyLojpFKwJUfjI4UAOeDDAC1sVvxjR74z7Wq8IshNVvcelyHi0OxVf1g/W9G+J0OKVVhZEsJ1ofNjPfvBeTQwTjY7c+5OvPvfQ9aT4jCzXYxEicXcw+1ws/dkRjIdQdga8ewwocxzsK1ISWVHR43zTJnRPj9MozzhobZkqfkNySCzN8trM=" Oct 12 12:12:07 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:07.114+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.240:43056,00:00:00:00:00:00%01 @ 0x25ff0e0" latency=-1.444991211s timeout=10s endpoint=https://functions.volumio.cloud duration=3.313854113s Oct 12 12:12:07 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:07.114+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.240:43056,00:00:00:00:00:00%01 @ 0x25ff0e0" latency=-1.444991211s timeout=10s endpoint=https://functions.volumio.cloud duration=3.323594374s Oct 12 12:12:07 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 12:12:07 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 12:12:07 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Oct 12 12:12:07 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Oct 12 12:12:07 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Oct 12 12:12:07 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Oct 12 12:12:07 muziekspeler volumio[1200]: info: CoreCommandRouter::volumioGetBrowseSources Oct 12 12:12:07 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 12 12:12:07 muziekspeler go-librespot[2235]: time="2026-10-12T12:12:07+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 12:12:07 muziekspeler go-librespot[2235]: time="2026-10-12T12:12:07+02:00" level=debug msg="completed keyexchange" Oct 12 12:12:07 muziekspeler go-librespot[2235]: time="2026-10-12T12:12:07+02:00" level=debug msg="completed challenge" Oct 12 12:12:07 muziekspeler go-librespot[2235]: time="2026-10-12T12:12:07+02:00" level=info msg="authenticated AP" username="do**ey" Oct 12 12:12:07 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 12 12:12:07 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 12 12:12:07 muziekspeler go-librespot[2235]: time="2026-10-12T12:12:07+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 12:12:07 muziekspeler systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 12:12:07 muziekspeler systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 12:12:07 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:07.847+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.240:43056,00:00:00:00:00:00%01 @ 0x25ff0e0" latency=-1.444991211s timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=4.047335832s Oct 12 12:12:07 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:07.906+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.240:43056,00:00:00:00:00:00%01 @ 0x25ff0e0" latency=-1.444991211s timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=4.115855259s Oct 12 12:12:07 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:07.974+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.240:43056,00:00:00:00:00:00%01 @ 0x25ff0e0" latency=-1.444991211s timeout=10s endpoint=https://database.volumio.cloud duration=4.149938645s Oct 12 12:12:08 muziekspeler volumio[1200]: info: Initializing connection to go-librespot Websocket Oct 12 12:12:08 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:08.491+02:00 level=INFO msg="service successfully established" component=discovery/localnet Oct 12 12:12:09 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 12 12:12:09 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 12 12:12:09 muziekspeler volumio[1200]: info: Discovery: Getting this device information Oct 12 12:12:09 muziekspeler volumio[1200]: info: CoreCommandRouter::volumioGetState Oct 12 12:12:09 muziekspeler volumio[1200]: info: CorePlayQueue::getTrack 0 Oct 12 12:12:09 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 12 12:12:10 muziekspeler volumio[1200]: error: MyVolumio Custom Token format not valid, refreshing it Oct 12 12:12:10 muziekspeler systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Oct 12 12:12:10 muziekspeler systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 12:12:10 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 12 12:12:10 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 12 12:12:10 muziekspeler volumio[1200]: info: Discovery: Getting this device information Oct 12 12:12:10 muziekspeler volumio[1200]: info: CoreCommandRouter::volumioGetState Oct 12 12:12:10 muziekspeler volumio[1200]: info: CorePlayQueue::getTrack 0 Oct 12 12:12:10 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 12 12:12:10 muziekspeler systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 12:12:10 muziekspeler go-librespot[2258]: go-librespot daemon starting... Oct 12 12:12:11 muziekspeler go-librespot[2259]: time="2026-10-12T12:12:11+02:00" level=info msg="running go-librespot 0.7.1" Oct 12 12:12:11 muziekspeler go-librespot[2259]: time="2026-10-12T12:12:11+02:00" level=debug msg="app state loaded" Oct 12 12:12:11 muziekspeler go-librespot[2259]: time="2026-10-12T12:12:11+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 12:12:11 muziekspeler volumio-remote-updater[742]: Test mode disabled Oct 12 12:12:11 muziekspeler volumio-remote-updater[742]: Alpha mode disabled Oct 12 12:12:11 muziekspeler volumio-remote-updater[742]: Alpha legacy test mode disabled Oct 12 12:12:11 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Oct 12 12:12:11 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:11.653+02:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.240:43056,00:00:00:00:00:00%01 @ 0x25ff0e0" latency=-1.451141162s timeout=10s Oct 12 12:12:11 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:11.667+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.240:43056,00:00:00:00:00:00%01 @ 0x25ff0e0" latency=-1.451141162s timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=14.044583ms Oct 12 12:12:11 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:11.672+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.240:43056,00:00:00:00:00:00%01 @ 0x25ff0e0" latency=-1.451141162s timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=16.827188ms Oct 12 12:12:11 muziekspeler go-librespot[2259]: time="2026-10-12T12:12:11+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Oct 12 12:12:11 muziekspeler go-librespot[2259]: time="2026-10-12T12:12:11+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Oct 12 12:12:11 muziekspeler go-librespot[2259]: time="2026-10-12T12:12:11+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Oct 12 12:12:11 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:11.687+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.240:43056,00:00:00:00:00:00%01 @ 0x25ff0e0" latency=-1.451141162s timeout=10s endpoint=http://pushupdates.volumio.org duration=31.400468ms Oct 12 12:12:11 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:11.687+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.240:43056,00:00:00:00:00:00%01 @ 0x25ff0e0" latency=-1.451141162s timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=31.399531ms Oct 12 12:12:11 muziekspeler volumio[1200]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 12:12:11 muziekspeler go-librespot[2259]: time="2026-10-12T12:12:11+02:00" level=info msg="zeroconf server listening on port 33869" Oct 12 12:12:11 muziekspeler go-librespot[2259]: time="2026-10-12T12:12:11+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Oct 12 12:12:11 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:11.805+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.240:43056,00:00:00:00:00:00%01 @ 0x25ff0e0" latency=-1.451141162s timeout=10s endpoint=https://google.com duration=151.690364ms Oct 12 12:12:11 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:11.805+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.240:43056,00:00:00:00:00:00%01 @ 0x25ff0e0" latency=-1.451141162s timeout=10s endpoint=https://www.googleapis.com duration=149.401094ms Oct 12 12:12:11 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:11.806+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.240:43056,00:00:00:00:00:00%01 @ 0x25ff0e0" latency=-1.451141162s timeout=10s endpoint=https://securetoken.googleapis.com duration=152.444271ms Oct 12 12:12:11 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:11.806+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.240:43056,00:00:00:00:00:00%01 @ 0x25ff0e0" latency=-1.451141162s timeout=10s endpoint=https://myvolumio.firebaseio.com duration=151.279323ms Oct 12 12:12:11 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:11.813+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.240:43056,00:00:00:00:00:00%01 @ 0x25ff0e0" latency=-1.451141162s timeout=10s endpoint=https://functions.volumio.cloud duration=158.649063ms Oct 12 12:12:11 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:11.814+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.240:43056,00:00:00:00:00:00%01 @ 0x25ff0e0" latency=-1.451141162s timeout=10s endpoint=https://functions.volumio.cloud duration=158.716979ms Oct 12 12:12:11 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:11.815+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.240:43056,00:00:00:00:00:00%01 @ 0x25ff0e0" latency=-1.451141162s timeout=10s endpoint=https://database.volumio.cloud duration=158.907656ms Oct 12 12:12:11 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 12 12:12:11 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 12 12:12:11 muziekspeler volumio[1200]: info: Discovery: Getting this device information Oct 12 12:12:11 muziekspeler volumio[1200]: info: CoreCommandRouter::volumioGetState Oct 12 12:12:11 muziekspeler volumio[1200]: info: CorePlayQueue::getTrack 0 Oct 12 12:12:11 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 12 12:12:12 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:12.027+02:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.240:43056,00:00:00:00:00:00%01 @ 0x25ff0e0" latency=-1.451141162s timeout=10s endpoint=http://cddb.volumio.org duration=373.517344ms error="Head \"http://gnudb.gnudb.org/~cddb/cddb.cgi/\": EOF" Oct 12 12:12:12 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:12.029+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.240:43056,00:00:00:00:00:00%01 @ 0x25ff0e0" latency=-1.451141162s timeout=10s endpoint=http://plugins.volumio.org duration=372.649687ms Oct 12 12:12:12 muziekspeler go-librespot[2259]: time="2026-10-12T12:12:12+02:00" level=debug msg="obtained new client token: AAGeyUZC+Ch4KBUcv7aEFrvksp84JNszSneUrUoBD1EC3VpVeKAyiqknOjGvibes3bA3u9GCv0vNDytghJU7ZmVoLG57X1XzA0hFu6+DS3eRxZrGgXCJrk0CKqTuukMkjesjslECsj0au3wRKz65wJOP1wLk5nx9f6Qlc9Fjs3gqpYeXNu6qZHf17ejYhzxXOu7b1yrX4Yd6RXbMQEfNOVhwmvqMx8MRP04sfGN21OinNvSF51cRP9Y=" Oct 12 12:12:12 muziekspeler go-librespot[2259]: time="2026-10-12T12:12:12+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 12:12:12 muziekspeler go-librespot[2259]: time="2026-10-12T12:12:12+02:00" level=debug msg="completed keyexchange" Oct 12 12:12:12 muziekspeler go-librespot[2259]: time="2026-10-12T12:12:12+02:00" level=debug msg="completed challenge" Oct 12 12:12:12 muziekspeler go-librespot[2259]: time="2026-10-12T12:12:12+02:00" level=info msg="authenticated AP" username="do**ey" Oct 12 12:12:12 muziekspeler go-librespot[2259]: time="2026-10-12T12:12:12+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 12:12:12 muziekspeler systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 12:12:12 muziekspeler systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 12:12:12 muziekspeler volumio[1200]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Oct 12 12:12:12 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Oct 12 12:12:12 muziekspeler volumio[1200]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Oct 12 12:12:13 muziekspeler volumio[1200]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Oct 12 12:12:14 muziekspeler volumio[1200]: info: Initializing connection to go-librespot Websocket Oct 12 12:12:15 muziekspeler volumio[1200]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 12:12:15 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 12 12:12:15 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 12 12:12:15 muziekspeler volumio[1200]: info: Discovery: Getting this device information Oct 12 12:12:15 muziekspeler volumio[1200]: info: CoreCommandRouter::volumioGetState Oct 12 12:12:15 muziekspeler volumio[1200]: info: CorePlayQueue::getTrack 0 Oct 12 12:12:15 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 12 12:12:15 muziekspeler volumio[1200]: info: MyVolumio login type: Token Oct 12 12:12:15 muziekspeler systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Oct 12 12:12:15 muziekspeler systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 12:12:15 muziekspeler systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 12:12:15 muziekspeler go-librespot[2270]: go-librespot daemon starting... Oct 12 12:12:15 muziekspeler go-librespot[2271]: time="2026-10-12T12:12:15+02:00" level=info msg="running go-librespot 0.7.1" Oct 12 12:12:15 muziekspeler go-librespot[2271]: time="2026-10-12T12:12:15+02:00" level=debug msg="app state loaded" Oct 12 12:12:16 muziekspeler go-librespot[2271]: time="2026-10-12T12:12:16+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 12:12:16 muziekspeler go-librespot[2271]: time="2026-10-12T12:12:16+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Oct 12 12:12:16 muziekspeler go-librespot[2271]: time="2026-10-12T12:12:16+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Oct 12 12:12:16 muziekspeler go-librespot[2271]: time="2026-10-12T12:12:16+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Oct 12 12:12:16 muziekspeler go-librespot[2271]: time="2026-10-12T12:12:16+02:00" level=info msg="zeroconf server listening on port 46763" Oct 12 12:12:16 muziekspeler go-librespot[2271]: time="2026-10-12T12:12:16+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Oct 12 12:12:17 muziekspeler go-librespot[2271]: time="2026-10-12T12:12:17+02:00" level=debug msg="obtained new client token: AAGPngXlFwJTqQrJlrvgDqc6xbo007+1rtQNHNzGwSD4YETx6SypEjWuHAvUeI9uh/LgxRQ6G9a8yQVhX801hwth3SkkqnsNvldkw+peVTV/kbQBQ5sv5pmALXCa8ayVemXfOSlrCQXgKUHUHCK2X/M+ao6dHiaVbZyRs+1YlxgnnIt5FjNnrWXLCP8NacIe2MNNHSYpw1TLwm9iOdXfCQG8NLQjKe4biUCttWjWg1MD0PUiIdyQGQiTqg==" Oct 12 12:12:17 muziekspeler go-librespot[2271]: time="2026-10-12T12:12:17+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 12:12:17 muziekspeler go-librespot[2271]: time="2026-10-12T12:12:17+02:00" level=debug msg="completed keyexchange" Oct 12 12:12:17 muziekspeler go-librespot[2271]: time="2026-10-12T12:12:17+02:00" level=debug msg="completed challenge" Oct 12 12:12:17 muziekspeler go-librespot[2271]: time="2026-10-12T12:12:17+02:00" level=info msg="authenticated AP" username="do**ey" Oct 12 12:12:17 muziekspeler volumio[1200]: info: CoreCommandRouter::volumioGetState Oct 12 12:12:17 muziekspeler go-librespot[2271]: time="2026-10-12T12:12:17+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 12:12:17 muziekspeler systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 12:12:17 muziekspeler systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 12:12:17 muziekspeler volumio[1200]: info: CorePlayQueue::getTrack 0 Oct 12 12:12:18 muziekspeler volumio[1200]: info: Initializing connection to go-librespot Websocket Oct 12 12:12:19 muziekspeler volumio[1200]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 12:12:20 muziekspeler volumio[1200]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Oct 12 12:12:20 muziekspeler systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Oct 12 12:12:20 muziekspeler systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 12:12:20 muziekspeler go-librespot[2294]: go-librespot daemon starting... Oct 12 12:12:20 muziekspeler systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 12:12:20 muziekspeler go-librespot[2295]: time="2026-10-12T12:12:20+02:00" level=info msg="running go-librespot 0.7.1" Oct 12 12:12:20 muziekspeler go-librespot[2295]: time="2026-10-12T12:12:20+02:00" level=debug msg="app state loaded" Oct 12 12:12:20 muziekspeler go-librespot[2295]: time="2026-10-12T12:12:20+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 12:12:21 muziekspeler go-librespot[2295]: time="2026-10-12T12:12:21+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 12 12:12:21 muziekspeler go-librespot[2295]: time="2026-10-12T12:12:21+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 12 12:12:21 muziekspeler go-librespot[2295]: time="2026-10-12T12:12:21+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 12 12:12:21 muziekspeler go-librespot[2295]: time="2026-10-12T12:12:21+02:00" level=info msg="zeroconf server listening on port 37667" Oct 12 12:12:21 muziekspeler go-librespot[2295]: time="2026-10-12T12:12:21+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Oct 12 12:12:21 muziekspeler go-librespot[2295]: time="2026-10-12T12:12:21+02:00" level=debug msg="obtained new client token: AAFmm1AFJY53hpNvUHD5htIvv+X51Ki9HuE/ndPP+KuhZPYp3111cG19RAjYqJz8B6Duj5HQXSHIwFQjDj33eTX8A1wytPfCb6VKW0FdOl3gv2ktVfhLTY1B51rFAnID0+tx77NpmkTtriZRjzlb5BaKr0bE1IssO61OyMLpJeR3j+cwZL2uXmzpvirEHP13X5/k2GKE3DZFAlEIgByc5BosFC1xhGFg2OaAnP8REaVc69IDaBstnq4PiQ==" Oct 12 12:12:22 muziekspeler go-librespot[2295]: time="2026-10-12T12:12:22+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 12:12:22 muziekspeler go-librespot[2295]: time="2026-10-12T12:12:22+02:00" level=debug msg="completed keyexchange" Oct 12 12:12:22 muziekspeler go-librespot[2295]: time="2026-10-12T12:12:22+02:00" level=debug msg="completed challenge" Oct 12 12:12:22 muziekspeler go-librespot[2295]: time="2026-10-12T12:12:22+02:00" level=info msg="authenticated AP" username="do**ey" Oct 12 12:12:22 muziekspeler volumio[1200]: error: MyVolumio Plugin failed to authenticate in a timely fashion Oct 12 12:12:22 muziekspeler volumio[1200]: info: Completed starting MyVolumio Plugin Oct 12 12:12:22 muziekspeler volumio[1200]: [Metrics] CommandRouter: 129s 302.01ms Oct 12 12:12:22 muziekspeler volumio[1200]: info: CoreCommandRouter::volumiosetStartupVolume Oct 12 12:12:22 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 12:12:22 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 12:12:22 muziekspeler go-librespot[2295]: time="2026-10-12T12:12:22+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 12:12:22 muziekspeler volumio[1200]: info: CoreCommandRouter::Close All Modals sent Oct 12 12:12:22 muziekspeler systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 12:12:22 muziekspeler systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 12:12:22 muziekspeler volumio[1200]: info: CoreCommandRouter::Close All Modals sent Oct 12 12:12:22 muziekspeler volumio[1200]: info: Initializing connection to go-librespot Websocket Oct 12 12:12:22 muziekspeler volumio[1200]: info: MyVolumio token set successfully Oct 12 12:12:22 muziekspeler volumio[1200]: info: MYVOLUMIO: Adding device Oct 12 12:12:22 muziekspeler volumio[1200]: info: MYVOLUMIO: Evaluating Server Oct 12 12:12:22 muziekspeler volumio[1200]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 12:12:25 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Oct 12 12:12:25 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 12 12:12:25 muziekspeler systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Oct 12 12:12:25 muziekspeler systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 12:12:25 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Oct 12 12:12:25 muziekspeler systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 12:12:25 muziekspeler go-librespot[2327]: go-librespot daemon starting... Oct 12 12:12:25 muziekspeler go-librespot[2328]: time="2026-10-12T12:12:25+02:00" level=info msg="running go-librespot 0.7.1" Oct 12 12:12:25 muziekspeler go-librespot[2328]: time="2026-10-12T12:12:25+02:00" level=debug msg="app state loaded" Oct 12 12:12:25 muziekspeler volumio[1200]: info: MyVolumio status changed Oct 12 12:12:25 muziekspeler volumio[1200]: info: Streaming services startup Oct 12 12:12:25 muziekspeler volumio[1200]: info: Starting Streaming Daemon Oct 12 12:12:25 muziekspeler go-librespot[2328]: time="2026-10-12T12:12:25+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 12:12:26 muziekspeler volumio[1200]: info: Removing browser output: myVolumio user plan is not superstar Oct 12 12:12:26 muziekspeler volumio[1200]: info: Removing audio output: Oct 12 12:12:26 muziekspeler volumio[1200]: info: Stoppping Tunnel 1 Oct 12 12:12:26 muziekspeler go-librespot[2328]: time="2026-10-12T12:12: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-gew1.spotify.com:80]" Oct 12 12:12:26 muziekspeler go-librespot[2328]: time="2026-10-12T12:12:26+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Oct 12 12:12:26 muziekspeler go-librespot[2328]: time="2026-10-12T12:12:26+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Oct 12 12:12:26 muziekspeler go-librespot[2328]: time="2026-10-12T12:12:26+02:00" level=info msg="zeroconf server listening on port 34523" Oct 12 12:12:26 muziekspeler go-librespot[2328]: time="2026-10-12T12:12:26+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Oct 12 12:12:27 muziekspeler sudo[2338]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 12 12:12:27 muziekspeler sudo[2338]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 12:12:27 muziekspeler volumio[1200]: info: Initializing connection to go-librespot Websocket Oct 12 12:12:27 muziekspeler sudo[2340]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Oct 12 12:12:27 muziekspeler sudo[2340]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 12:12:27 muziekspeler go-librespot[2328]: time="2026-10-12T12:12:27+02:00" level=debug msg="obtained new client token: AAG/Kwzt1spDrHKF8rvOHFJIZPPPgEwct2c0YcMh1FAlIyyG+6tWwx1HaQ2IJBka5MWf0HK1dUqjAVCiXAeSx7ARXl+xD79kRAK+DqMMzmJ9SCWuMHq4Yvn3iJ5tDaFeQjpbAnM/NFOH10s2bxYYZXA2DvJNsq7hxeF3SeMGH7/nDLNazkL5Vx9IsCsUzfWeaEYi0eD8yruOM5zloY5avLjnuqd9YAwK3pbq3jIevYPLCaEeNJLN3DpfjA==" Oct 12 12:12:27 muziekspeler volumio[1200]: info: Setting Geolocation for MyVolumio to eu9 Oct 12 12:12:28 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 12:12:28 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 12:12:28 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 12:12:28 muziekspeler systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 12:12:28 muziekspeler systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 12:12:28 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 12 12:12:28 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 12 12:12:28 muziekspeler volumio[1200]: info: Discovery: Getting this device information Oct 12 12:12:28 muziekspeler volumio[1200]: info: CoreCommandRouter::volumioGetState Oct 12 12:12:28 muziekspeler volumio[1200]: info: CorePlayQueue::getTrack 0 Oct 12 12:12:28 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 12 12:12:28 muziekspeler systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 12:12:28 muziekspeler systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 12:12:28 muziekspeler systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 12:12:28 muziekspeler systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 12:12:28 muziekspeler systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 12:12:28 muziekspeler systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 12:12:28 muziekspeler sudo[2338]: pam_unix(sudo:session): session closed for user root Oct 12 12:12:28 muziekspeler go-librespot[2328]: time="2026-10-12T12:12:28+02:00" level=debug msg="new websocket client" Oct 12 12:12:28 muziekspeler sudo[2340]: pam_unix(sudo:session): session closed for user root Oct 12 12:12:28 muziekspeler volumio[1200]: info: Connection to go-librespot Websocket established Oct 12 12:12:28 muziekspeler volumio[1200]: error: Cannot start Volumio Streaming Daemon Oct 12 12:12:28 muziekspeler volumio[1200]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 12 12:12:28 muziekspeler volumio[1200]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 12 12:12:28 muziekspeler volumio[1200]: info: Remote SSH Stopped Oct 12 12:12:29 muziekspeler volumio[1200]: info: Updating MyVolumio device info Oct 12 12:12:29 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 12:12:29 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 12:12:29 muziekspeler volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 12:12:29 muziekspeler volumio[1200]: info: BOOT COMPLETED Oct 12 12:12:29 muziekspeler volumio[1200]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/147.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Oct 12 12:12:31 muziekspeler volumio[1200]: info: Getting Spotify volume Oct 12 12:12:31 muziekspeler volumio[1200]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Oct 12 12:12:32 muziekspeler volumio[1200]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Oct 12 12:12:32 muziekspeler go-librespot[2328]: time="2026-10-12T12:12:32+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 12:12:32 muziekspeler go-librespot[2328]: time="2026-10-12T12:12:32+02:00" level=debug msg="completed keyexchange" Oct 12 12:12:32 muziekspeler go-librespot[2328]: time="2026-10-12T12:12:32+02:00" level=debug msg="completed challenge" Oct 12 12:12:32 muziekspeler go-librespot[2328]: time="2026-10-12T12:12:32+02:00" level=info msg="authenticated AP" username="do**ey" Oct 12 12:12:33 muziekspeler volumio[1200]: info: CoreCommandRouter::volumioGetState Oct 12 12:12:33 muziekspeler volumio[1200]: info: CorePlayQueue::getTrack 0 Oct 12 12:12:34 muziekspeler go-librespot[2328]: time="2026-10-12T12:12:34+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 12:12:35 muziekspeler systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 12:12:35 muziekspeler systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 12:12:35 muziekspeler volumio[1200]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 12:12:35 muziekspeler volumio[1200]: Error: socket hang up Oct 12 12:12:35 muziekspeler volumio[1200]: at connResetException (node:internal/errors:720:14) Oct 12 12:12:35 muziekspeler volumio[1200]: at Socket.socketOnEnd (node:_http_client:519:23) Oct 12 12:12:35 muziekspeler volumio[1200]: at Socket.emit (node:events:526:35) Oct 12 12:12:35 muziekspeler volumio[1200]: at endReadableNT (node:internal/streams/readable:1376:12) Oct 12 12:12:35 muziekspeler volumio[1200]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Oct 12 12:12:35 muziekspeler volumio[1200]: code: 'ECONNRESET', Oct 12 12:12:35 muziekspeler volumio[1200]: response: undefined Oct 12 12:12:35 muziekspeler volumio[1200]: } Oct 12 12:12:35 muziekspeler volumio[1200]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 12:12:38 muziekspeler systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Oct 12 12:12:38 muziekspeler systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 12:12:38 muziekspeler systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 12:12:38 muziekspeler go-librespot[2366]: go-librespot daemon starting... Oct 12 12:12:38 muziekspeler go-librespot[2367]: time="2026-10-12T12:12:38+02:00" level=info msg="running go-librespot 0.7.1" Oct 12 12:12:38 muziekspeler go-librespot[2367]: time="2026-10-12T12:12:38+02:00" level=debug msg="app state loaded" Oct 12 12:12:38 muziekspeler go-librespot[2367]: time="2026-10-12T12:12:38+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 12:12:40 muziekspeler go-librespot[2367]: time="2026-10-12T12:12:40+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Oct 12 12:12:40 muziekspeler go-librespot[2367]: time="2026-10-12T12:12:40+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Oct 12 12:12:40 muziekspeler go-librespot[2367]: time="2026-10-12T12:12:40+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Oct 12 12:12:40 muziekspeler go-librespot[2367]: time="2026-10-12T12:12:40+02:00" level=info msg="zeroconf server listening on port 44465" Oct 12 12:12:40 muziekspeler go-librespot[2367]: time="2026-10-12T12:12:40+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Oct 12 12:12:40 muziekspeler go-librespot[2367]: time="2026-10-12T12:12:40+02:00" level=debug msg="obtained new client token: AAG1H8dAkIYyBJaSrDLY45mvLR2l8xrgfeE687oieQCpYJ0RXZkTeOdFocsG09MhUSwxiS+ToDCg/A2i9Mz5OJsxzX/0EeT6BguCjcR5NJ5oIIn2SwaHbxHeNREFPLq+8qsb8xN+qUPCEBDnqTJ0NKERhySXNhnP+e2lPmEHZ4PF3owgIQBH47UyB94bHc47atFCyydhFD/7wrsFtwXICjWQEaGLYkz7dRuzK9cILVcQqxEgMl3ZeDg9vg==" Oct 12 12:12:40 muziekspeler go-librespot[2367]: time="2026-10-12T12:12:40+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 12:12:41 muziekspeler go-librespot[2367]: time="2026-10-12T12:12:41+02:00" level=debug msg="completed keyexchange" Oct 12 12:12:41 muziekspeler go-librespot[2367]: time="2026-10-12T12:12:41+02:00" level=debug msg="completed challenge" Oct 12 12:12:41 muziekspeler go-librespot[2367]: time="2026-10-12T12:12:41+02:00" level=info msg="authenticated AP" username="do**ey" Oct 12 12:12:42 muziekspeler go-librespot[2367]: time="2026-10-12T12:12:42+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 12:12:42 muziekspeler systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 12:12:42 muziekspeler systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 12:12:45 muziekspeler systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Oct 12 12:12:45 muziekspeler systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 12:12:45 muziekspeler systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 12:12:45 muziekspeler go-librespot[2443]: go-librespot daemon starting... Oct 12 12:12:45 muziekspeler go-librespot[2444]: time="2026-10-12T12:12:45+02:00" level=info msg="running go-librespot 0.7.1" Oct 12 12:12:45 muziekspeler go-librespot[2444]: time="2026-10-12T12:12:45+02:00" level=debug msg="app state loaded" Oct 12 12:12:46 muziekspeler go-librespot[2444]: time="2026-10-12T12:12:46+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 12:12:47 muziekspeler go-librespot[2444]: time="2026-10-12T12:12:47+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 12 12:12:47 muziekspeler go-librespot[2444]: time="2026-10-12T12:12:47+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 12 12:12:47 muziekspeler go-librespot[2444]: time="2026-10-12T12:12:47+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 12 12:12:47 muziekspeler go-librespot[2444]: time="2026-10-12T12:12:47+02:00" level=info msg="zeroconf server listening on port 38199" Oct 12 12:12:47 muziekspeler go-librespot[2444]: time="2026-10-12T12:12:47+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Oct 12 12:12:47 muziekspeler go-librespot[2444]: time="2026-10-12T12:12:47+02:00" level=debug msg="obtained new client token: AAE/YPcrqCok+9fFL4J71dzJqzK0tnZlpxKHVi8Yd3kLNfi3bnajlII1+SDxBM5Ewi6Rz0NJxE72sUYjTpW/HbmKB52GN+udWgAFVAHD039ALGJRvUFtADVq42Ef1LuXBUfM5/6Zgpxge+fTGXBBaX1aH2wwhmjUPeyaBr8+UibX3i2E7HgfHm3JpU3UivprzJw2AGNa4j5xMBQe8WV5ISsT7mMEvUywIsFLlRlX9zlbZbEEgFee9luCIQ==" Oct 12 12:12:47 muziekspeler go-librespot[2444]: time="2026-10-12T12:12:47+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 12:12:47 muziekspeler go-librespot[2444]: time="2026-10-12T12:12:47+02:00" level=debug msg="completed keyexchange" Oct 12 12:12:47 muziekspeler go-librespot[2444]: time="2026-10-12T12:12:47+02:00" level=debug msg="completed challenge" Oct 12 12:12:47 muziekspeler go-librespot[2444]: time="2026-10-12T12:12:47+02:00" level=info msg="authenticated AP" username="do**ey" Oct 12 12:12:48 muziekspeler go-librespot[2444]: time="2026-10-12T12:12:48+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 12:12:48 muziekspeler systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 12:12:48 muziekspeler systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 12:12:48 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:48.566+02:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.1.240:43056,00:00:00:00:00:00%01 @ 0x25ff0e0" latency=-1.395101697s timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Oct 12 12:12:51 muziekspeler systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Oct 12 12:12:51 muziekspeler systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 12:12:51 muziekspeler systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 12:12:51 muziekspeler go-librespot[2482]: go-librespot daemon starting... Oct 12 12:12:51 muziekspeler go-librespot[2483]: time="2026-10-12T12:12:51+02:00" level=info msg="running go-librespot 0.7.1" Oct 12 12:12:51 muziekspeler go-librespot[2483]: time="2026-10-12T12:12:51+02:00" level=debug msg="app state loaded" Oct 12 12:12:51 muziekspeler go-librespot[2483]: time="2026-10-12T12:12:51+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 12:12:54 muziekspeler go-librespot[2483]: time="2026-10-12T12:12:54+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 12 12:12:54 muziekspeler go-librespot[2483]: time="2026-10-12T12:12:54+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 12 12:12:54 muziekspeler go-librespot[2483]: time="2026-10-12T12:12:54+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 12 12:12:54 muziekspeler go-librespot[2483]: time="2026-10-12T12:12:54+02:00" level=info msg="zeroconf server listening on port 37229" Oct 12 12:12:54 muziekspeler go-librespot[2483]: time="2026-10-12T12:12:54+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Oct 12 12:12:55 muziekspeler go-librespot[2483]: time="2026-10-12T12:12:55+02:00" level=debug msg="obtained new client token: AAEdmBoWDiH2KGzcH/+4/U9oQb3tPw1XzQ9OxKhbf+tdzHPGwxn3+yCC4TbK+RxaieQOhs8B5TMY5bP5QvIFLltSMbMcfhgF2A7SwP16CZdSnAvvzh9Z7ivamSCjKsgwFgKcU4+YVYZghh6R7gnLSWnTnku08jbEPUaTuP4+sS8mRH2zSHOEGKNqRC5KKkZc9YfRd96Bp3VLOOyGP1OFnVMFyXzCLNl/iLyQ6so3kX8P1FbDvfb0y6w=" Oct 12 12:12:55 muziekspeler go-librespot[2483]: time="2026-10-12T12:12:55+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 12:12:55 muziekspeler go-librespot[2483]: time="2026-10-12T12:12:55+02:00" level=debug msg="completed keyexchange" Oct 12 12:12:55 muziekspeler go-librespot[2483]: time="2026-10-12T12:12:55+02:00" level=debug msg="completed challenge" Oct 12 12:12:55 muziekspeler go-librespot[2483]: time="2026-10-12T12:12:55+02:00" level=info msg="authenticated AP" username="do**ey" Oct 12 12:12:56 muziekspeler go-librespot[2483]: time="2026-10-12T12:12:56+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 12:12:56 muziekspeler systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 12:12:56 muziekspeler systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 12:12:56 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:56.413+02:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.1.114:48434 Oct 12 12:12:56 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:56.492+02:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.1.240:43056,00:00:00:00:00:00%01,192.168.1.114:48434 @ 0x25ff0e0" latency=-1.429333471s timeout=20s Oct 12 12:12:56 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:56.492+02:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.1.240:43056,00:00:00:00:00:00%01,192.168.1.114:48434 @ 0x25ff0e0" Oct 12 12:12:59 muziekspeler systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Oct 12 12:12:59 muziekspeler systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 12:12:59 muziekspeler systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 12:12:59 muziekspeler go-librespot[2508]: go-librespot daemon starting... Oct 12 12:12:59 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:59.421+02:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.1.240:43056,00:00:00:00:00:00%01,192.168.1.114:48434 @ 0x25ff0e0" latency=-1.44232191s timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Oct 12 12:12:59 muziekspeler go-librespot[2509]: time="2026-10-12T12:12:59+02:00" level=info msg="running go-librespot 0.7.1" Oct 12 12:12:59 muziekspeler go-librespot[2509]: time="2026-10-12T12:12:59+02:00" level=debug msg="app state loaded" Oct 12 12:12:59 muziekspeler go-librespot[2509]: time="2026-10-12T12:12:59+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 12:12:59 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:59.617+02:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.240:43056,00:00:00:00:00:00%01,192.168.1.114:48434 @ 0x25ff0e0" latency=-1.338876233s timeout=10s Oct 12 12:12:59 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:59.801+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.240:43056,00:00:00:00:00:00%01,192.168.1.114:48434 @ 0x25ff0e0" latency=-1.338876233s timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=30.48375ms Oct 12 12:12:59 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:59.813+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.240:43056,00:00:00:00:00:00%01,192.168.1.114:48434 @ 0x25ff0e0" latency=-1.338876233s timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=192.218333ms Oct 12 12:12:59 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:59.822+02:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.1.114:47388 Oct 12 12:12:59 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:59.840+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.240:43056,00:00:00:00:00:00%01,192.168.1.114:48434 @ 0x25ff0e0" latency=-1.338876233s timeout=10s endpoint=https://google.com duration=220.615782ms Oct 12 12:12:59 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:59.899+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.240:43056,00:00:00:00:00:00%01,192.168.1.114:48434 @ 0x25ff0e0" latency=-1.338876233s timeout=10s endpoint=https://www.googleapis.com duration=278.546614ms Oct 12 12:12:59 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:59.916+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.240:43056,00:00:00:00:00:00%01,192.168.1.114:48434 @ 0x25ff0e0" latency=-1.338876233s timeout=10s endpoint=https://myvolumio.firebaseio.com duration=289.264687ms Oct 12 12:12:59 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:12:59.965+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.240:43056,00:00:00:00:00:00%01,192.168.1.114:48434 @ 0x25ff0e0" latency=-1.338876233s timeout=10s endpoint=https://securetoken.googleapis.com duration=342.036145ms Oct 12 12:13:00 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:13:00.526+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.240:43056,00:00:00:00:00:00%01,192.168.1.114:48434 @ 0x25ff0e0" latency=-1.338876233s timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=908.229375ms Oct 12 12:13:00 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:13:00.559+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.240:43056,00:00:00:00:00:00%01,192.168.1.114:48434 @ 0x25ff0e0" latency=-1.338876233s timeout=10s endpoint=http://pushupdates.volumio.org duration=936.547916ms Oct 12 12:13:00 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:13:00.731+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.240:43056,00:00:00:00:00:00%01,192.168.1.114:48434 @ 0x25ff0e0" latency=-1.338876233s timeout=10s endpoint=https://functions.volumio.cloud duration=1.106035468s Oct 12 12:13:00 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:13:00.765+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.240:43056,00:00:00:00:00:00%01,192.168.1.114:48434 @ 0x25ff0e0" latency=-1.338876233s timeout=10s endpoint=https://functions.volumio.cloud duration=1.141625469s Oct 12 12:13:00 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:13:00.791+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.240:43056,00:00:00:00:00:00%01,192.168.1.114:48434 @ 0x25ff0e0" latency=-1.338876233s timeout=10s endpoint=https://database.volumio.cloud duration=1.167183228s Oct 12 12:13:01 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:13:01.349+02:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.1.114:47376 Oct 12 12:13:01 muziekspeler go-librespot[2509]: time="2026-10-12T12:13: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-gew1.spotify.com:80]" Oct 12 12:13:01 muziekspeler go-librespot[2509]: time="2026-10-12T12:13:01+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Oct 12 12:13:01 muziekspeler go-librespot[2509]: time="2026-10-12T12:13:01+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Oct 12 12:13:01 muziekspeler go-librespot[2509]: time="2026-10-12T12:13:01+02:00" level=info msg="zeroconf server listening on port 42407" Oct 12 12:13:01 muziekspeler go-librespot[2509]: time="2026-10-12T12:13:01+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Oct 12 12:13:03 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:13:03.007+02:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.240:43056,00:00:00:00:00:00%01,192.168.1.114:48434 @ 0x25ff0e0" latency=-1.338876233s timeout=10s endpoint=http://cddb.volumio.org duration=3.386040103s error="Head \"http://gnudb.gnudb.org/~cddb/cddb.cgi/\": EOF" Oct 12 12:13:03 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:13:03.155+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.240:43056,00:00:00:00:00:00%01,192.168.1.114:48434 @ 0x25ff0e0" latency=-1.338876233s timeout=10s endpoint=http://plugins.volumio.org duration=3.532203644s Oct 12 12:13:03 muziekspeler go-librespot[2509]: time="2026-10-12T12:13:03+02:00" level=debug msg="obtained new client token: AAFF9SK93pCW+y3huZ0335Rv8N5Cj+S2G+Hkrp+QKcokDYc8gLIogQJ27EXMcuU8CqthXxNgSIIigQ2kKDBa5cusKqDJeQ/bgl2eHx0ID/eb/XhFRZfB6+3SED0M09X0n7iPVbQ7vgON0oOyQb2VOCawLG5UW80J6y7pjUMdQgFK5XnDX8zZ6Jn3DLtcj473qs9K4EiumP/MJOorYTwl9kp9KH14MUpFAPobZCvnzHX8a30lP6CXuLKB8g==" Oct 12 12:13:03 muziekspeler go-librespot[2509]: time="2026-10-12T12:13:03+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 12:13:03 muziekspeler go-librespot[2509]: time="2026-10-12T12:13:03+02:00" level=debug msg="completed keyexchange" Oct 12 12:13:03 muziekspeler go-librespot[2509]: time="2026-10-12T12:13:03+02:00" level=debug msg="completed challenge" Oct 12 12:13:03 muziekspeler go-librespot[2509]: time="2026-10-12T12:13:03+02:00" level=info msg="authenticated AP" username="do**ey" Oct 12 12:13:04 muziekspeler go-librespot[2509]: time="2026-10-12T12:13:04+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 12:13:04 muziekspeler systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 12:13:04 muziekspeler systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 12:13:04 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:13:04.358+02:00 level=ERROR msg="failed to read message" component=conn/ws remoteAddr=192.168.1.114:48434 error="websocket: close 1006 (abnormal closure): unexpected EOF" Oct 12 12:13:04 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:13:04.359+02:00 level=ERROR msg="failed to read message" component=conn/ws remoteAddr=192.168.1.114:47388 error="websocket: close 1006 (abnormal closure): unexpected EOF" Oct 12 12:13:04 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:13:04.359+02:00 level=ERROR msg="failed to read message" component=conn/ws remoteAddr=192.168.1.114:47376 error="websocket: close 1006 (abnormal closure): unexpected EOF" Oct 12 12:13:04 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:13:04.429+02:00 level=INFO msg="WebSocket connection closed" component=conn/ws remoteAddr=192.168.1.114:47376 Oct 12 12:13:04 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:13:04.429+02:00 level=INFO msg="connection to address closed" component=conn/multi addr=192.168.1.114:47376 Oct 12 12:13:04 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:13:04.429+02:00 level=INFO msg="WebSocket connection closed" component=conn/ws remoteAddr=192.168.1.114:48434 Oct 12 12:13:04 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:13:04.430+02:00 level=INFO msg="connection to address closed" component=conn/multi addr=192.168.1.114:48434 Oct 12 12:13:04 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:13:04.434+02:00 level=INFO msg="WebSocket connection closed" component=conn/ws remoteAddr=192.168.1.114:47388 Oct 12 12:13:04 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:13:04.434+02:00 level=INFO msg="connection to address closed" component=conn/multi addr=192.168.1.114:47388 Oct 12 12:13:07 muziekspeler systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Oct 12 12:13:07 muziekspeler systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 12:13:07 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:13:07.314+02:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.1.114:59012 Oct 12 12:13:07 muziekspeler systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 12:13:07 muziekspeler go-librespot[2545]: go-librespot daemon starting... Oct 12 12:13:07 muziekspeler go-librespot[2546]: time="2026-10-12T12:13:07+02:00" level=info msg="running go-librespot 0.7.1" Oct 12 12:13:07 muziekspeler go-librespot[2546]: time="2026-10-12T12:13:07+02:00" level=debug msg="app state loaded" Oct 12 12:13:07 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:13:07.849+02:00 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.1.114:59012 @ 0x27e63f0" latency=-977.230038ms platform=PLATFORM_ANDROID version=6.260930.0 Oct 12 12:13:07 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:13:07.849+02:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.1.114:59012 @ 0x27e63f0" latency=-976.382642ms timeout=20s Oct 12 12:13:07 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:13:07.849+02:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.1.114:59012 @ 0x27e63f0" Oct 12 12:13:07 muziekspeler go-librespot[2546]: time="2026-10-12T12:13:07+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 12:13:08 muziekspeler go-librespot[2546]: time="2026-10-12T12:13:08+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 12 12:13:08 muziekspeler go-librespot[2546]: time="2026-10-12T12:13:08+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 12 12:13:08 muziekspeler go-librespot[2546]: time="2026-10-12T12:13:08+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 12 12:13:08 muziekspeler go-librespot[2546]: time="2026-10-12T12:13:08+02:00" level=info msg="zeroconf server listening on port 44047" Oct 12 12:13:09 muziekspeler go-librespot[2546]: time="2026-10-12T12:13:09+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Oct 12 12:13:09 muziekspeler dbus-daemon[717]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.28" (uid=0 pid=1747 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.6" (uid=0 pid=975 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Oct 12 12:13:09 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:13:09.273+02:00 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.1.114:59012 @ 0x27e63f0" latency=-1.16912384s platform=PLATFORM_ANDROID version=6.260930.0 Oct 12 12:13:09 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:13:09.277+02:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.1.114:59012 @ 0x27e63f0" latency=-1.166063007s timeout=20s Oct 12 12:13:09 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:13:09.277+02:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.1.114:59012 @ 0x27e63f0" Oct 12 12:13:09 muziekspeler go-librespot[2546]: time="2026-10-12T12:13:09+02:00" level=debug msg="obtained new client token: AAHfnYATf7vZKGdAlR1D9VjIdkWlzMwIKtmA/ko2zJrhHEmA5A+cPkksok49zEkdNUF1d12gKJvQ4034Rjht3MOHXkMqlVM1BAyFBrF7aV2zejShLO+ix0a1nFsO8hYTAV1ts3+3dBhr4798tBLElGK9K122sdCsDcvY8vNQZDZtX1fmkKcu0O39E1BRdljQp+tOvOf2BiMnT/XaePgHad1TklGtOnifozBIifdjQyniFo0eFxEE2ec=" Oct 12 12:13:09 muziekspeler go-librespot[2546]: time="2026-10-12T12:13:09+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 12:13:09 muziekspeler go-librespot[2546]: time="2026-10-12T12:13:09+02:00" level=debug msg="completed keyexchange" Oct 12 12:13:09 muziekspeler go-librespot[2546]: time="2026-10-12T12:13:09+02:00" level=debug msg="completed challenge" Oct 12 12:13:09 muziekspeler go-librespot[2546]: time="2026-10-12T12:13:09+02:00" level=info msg="authenticated AP" username="do**ey" Oct 12 12:13:10 muziekspeler go-librespot[2546]: time="2026-10-12T12:13:10+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 12:13:10 muziekspeler systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 12:13:10 muziekspeler systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 12:13:12 muziekspeler bluealsa[1041]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_7B_13_B9_3A_41_AA, ...) Oct 12 12:13:13 muziekspeler systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Oct 12 12:13:13 muziekspeler systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 12:13:13 muziekspeler systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 12:13:13 muziekspeler go-librespot[2581]: go-librespot daemon starting... Oct 12 12:13:13 muziekspeler go-librespot[2582]: time="2026-10-12T12:13:13+02:00" level=info msg="running go-librespot 0.7.1" Oct 12 12:13:13 muziekspeler go-librespot[2582]: time="2026-10-12T12:13:13+02:00" level=debug msg="app state loaded" Oct 12 12:13:13 muziekspeler go-librespot[2582]: time="2026-10-12T12:13:13+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 12:13:15 muziekspeler go-librespot[2582]: time="2026-10-12T12:13:15+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 12 12:13:15 muziekspeler go-librespot[2582]: time="2026-10-12T12:13:15+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 12 12:13:15 muziekspeler go-librespot[2582]: time="2026-10-12T12:13:15+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 12 12:13:15 muziekspeler go-librespot[2582]: time="2026-10-12T12:13:15+02:00" level=info msg="zeroconf server listening on port 44335" Oct 12 12:13:15 muziekspeler go-librespot[2582]: time="2026-10-12T12:13:15+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Oct 12 12:13:15 muziekspeler sudo[2578]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-12 12:12' Oct 12 12:13:15 muziekspeler sudo[2578]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 12:13:15 muziekspeler go-librespot[2582]: time="2026-10-12T12:13:15+02:00" level=debug msg="obtained new client token: AAEYAs+rCBXbcvxY4qmn0HPW3P6gwwo3Jkl5b8XBsWrj3NwGPvFP6vYkdY+HJzyjhpVT2d1FzKvDhrmbrjJU/TEu1P05fFFFnDcNofEchZHRsDsHsaTUllKTQMuxcoAKwjn4rsK0isdTfUw4oEV8YMDfeeCn+OIfGAV9uZ75S0roLFw2RS+9xdbTxGcooDvs1g+EJ2AWU8R2+KSIjtKRrQFwMVLOxe76m5gl7s1SWtOGbj6aZ67pZyiaTA==" Oct 12 12:13:15 muziekspeler go-librespot[2582]: time="2026-10-12T12:13:15+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Oct 12 12:13:15 muziekspeler go-librespot[2582]: time="2026-10-12T12:13:15+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Oct 12 12:13:15 muziekspeler go-librespot[2582]: time="2026-10-12T12:13:15+02:00" level=debug msg="completed keyexchange" Oct 12 12:13:15 muziekspeler go-librespot[2582]: time="2026-10-12T12:13:15+02:00" level=debug msg="completed challenge" Oct 12 12:13:16 muziekspeler go-librespot[2582]: time="2026-10-12T12:13:16+02:00" level=info msg="authenticated AP" username="do**ey" Oct 12 12:13:16 muziekspeler go-librespot[2582]: time="2026-10-12T12:13:16+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 12:13:16 muziekspeler systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 12:13:16 muziekspeler systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 12:13:16 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:13:16.493+02:00 level=ERROR msg="failed to notify all device data" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.1.240:43056,00:00:00:00:00:00%01,192.168.1.114:48434 @ 0x25ff0e0" latency=-1.429333471s timeout=20s error="failed to get system info: could not get system info: context deadline exceeded" Oct 12 12:13:17 muziekspeler volumio5-onboarding[1747]: time=2026-10-12T12:13:17.250+02:00 level=INFO msg="new address was allocated" component=ble/conn old=2 new=3 Oct 12 12:13:17 muziekspeler dbus-daemon[717]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.28" (uid=0 pid=1747 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.6" (uid=0 pid=975 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"