Mar 24 08:00:02 volumio-jbl volumio[30760]: info: Initializing connection to go-librespot Websocket Mar 24 08:00:02 volumio-jbl volumio[30760]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 24 08:00:02 volumio-jbl systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 535. Mar 24 08:00:02 volumio-jbl systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 08:00:02 volumio-jbl systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 08:00:02 volumio-jbl go-librespot[6204]: go-librespot daemon starting... Mar 24 08:00:02 volumio-jbl go-librespot[6205]: time="2026-03-24T08:00:02+01:00" level=info msg="running go-librespot 0.6.2" Mar 24 08:00:02 volumio-jbl go-librespot[6205]: time="2026-03-24T08:00:02+01:00" level=debug msg="app state loaded" Mar 24 08:00:02 volumio-jbl go-librespot[6205]: time="2026-03-24T08:00:02+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 08:00:02 volumio-jbl go-librespot[6205]: time="2026-03-24T08:00:02+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 24 08:00:02 volumio-jbl systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 08:00:02 volumio-jbl systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 08:00:05 volumio-jbl volumio[30760]: info: Initializing connection to go-librespot Websocket Mar 24 08:00:05 volumio-jbl volumio[30760]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 24 08:00:05 volumio-jbl systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 536. Mar 24 08:00:05 volumio-jbl systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 08:00:05 volumio-jbl systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 08:00:05 volumio-jbl go-librespot[6213]: go-librespot daemon starting... Mar 24 08:00:05 volumio-jbl go-librespot[6214]: time="2026-03-24T08:00:05+01:00" level=info msg="running go-librespot 0.6.2" Mar 24 08:00:05 volumio-jbl go-librespot[6214]: time="2026-03-24T08:00:05+01:00" level=debug msg="app state loaded" Mar 24 08:00:05 volumio-jbl go-librespot[6214]: time="2026-03-24T08:00:05+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 08:00:05 volumio-jbl go-librespot[6214]: time="2026-03-24T08:00:05+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 24 08:00:05 volumio-jbl systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 08:00:05 volumio-jbl systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 08:00:08 volumio-jbl volumio[30760]: info: Initializing connection to go-librespot Websocket Mar 24 08:00:08 volumio-jbl volumio[30760]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 24 08:00:09 volumio-jbl systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 537. Mar 24 08:00:09 volumio-jbl systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 08:00:09 volumio-jbl systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 08:00:09 volumio-jbl go-librespot[6236]: go-librespot daemon starting... Mar 24 08:00:09 volumio-jbl go-librespot[6237]: time="2026-03-24T08:00:09+01:00" level=info msg="running go-librespot 0.6.2" Mar 24 08:00:09 volumio-jbl go-librespot[6237]: time="2026-03-24T08:00:09+01:00" level=debug msg="app state loaded" Mar 24 08:00:09 volumio-jbl go-librespot[6237]: time="2026-03-24T08:00:09+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 08:00:09 volumio-jbl go-librespot[6237]: time="2026-03-24T08:00:09+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 24 08:00:09 volumio-jbl systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 08:00:09 volumio-jbl systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 08:00:11 volumio-jbl volumio[30760]: info: Initializing connection to go-librespot Websocket Mar 24 08:00:11 volumio-jbl volumio[30760]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 24 08:00:12 volumio-jbl systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 538. Mar 24 08:00:12 volumio-jbl systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 08:00:12 volumio-jbl systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 08:00:12 volumio-jbl go-librespot[6245]: go-librespot daemon starting... Mar 24 08:00:12 volumio-jbl go-librespot[6246]: time="2026-03-24T08:00:12+01:00" level=info msg="running go-librespot 0.6.2" Mar 24 08:00:12 volumio-jbl go-librespot[6246]: time="2026-03-24T08:00:12+01:00" level=debug msg="app state loaded" Mar 24 08:00:12 volumio-jbl go-librespot[6246]: time="2026-03-24T08:00:12+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 08:00:12 volumio-jbl go-librespot[6246]: time="2026-03-24T08:00:12+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 24 08:00:12 volumio-jbl systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 08:00:12 volumio-jbl systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 08:00:14 volumio-jbl volumio[30760]: info: Initializing connection to go-librespot Websocket Mar 24 08:00:14 volumio-jbl volumio[30760]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 24 08:00:15 volumio-jbl systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 539. Mar 24 08:00:15 volumio-jbl systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 08:00:15 volumio-jbl systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 08:00:15 volumio-jbl go-librespot[6255]: go-librespot daemon starting... Mar 24 08:00:15 volumio-jbl go-librespot[6256]: time="2026-03-24T08:00:15+01:00" level=info msg="running go-librespot 0.6.2" Mar 24 08:00:15 volumio-jbl go-librespot[6256]: time="2026-03-24T08:00:15+01:00" level=debug msg="app state loaded" Mar 24 08:00:15 volumio-jbl go-librespot[6256]: time="2026-03-24T08:00:15+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 08:00:15 volumio-jbl go-librespot[6256]: time="2026-03-24T08:00:15+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 24 08:00:15 volumio-jbl systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 08:00:15 volumio-jbl systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 08:00:17 volumio-jbl volumio[30760]: info: Initializing connection to go-librespot Websocket Mar 24 08:00:17 volumio-jbl volumio[30760]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 24 08:00:18 volumio-jbl systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 540. Mar 24 08:00:18 volumio-jbl systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 08:00:18 volumio-jbl systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 08:00:18 volumio-jbl go-librespot[6278]: go-librespot daemon starting... Mar 24 08:00:18 volumio-jbl go-librespot[6279]: time="2026-03-24T08:00:18+01:00" level=info msg="running go-librespot 0.6.2" Mar 24 08:00:18 volumio-jbl go-librespot[6279]: time="2026-03-24T08:00:18+01:00" level=debug msg="app state loaded" Mar 24 08:00:18 volumio-jbl go-librespot[6279]: time="2026-03-24T08:00:18+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 08:00:18 volumio-jbl go-librespot[6279]: time="2026-03-24T08:00:18+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 24 08:00:18 volumio-jbl systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 08:00:18 volumio-jbl systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 08:00:19 volumio-jbl wpa_supplicant[1193]: wlan0: CTRL-EVENT-SSID-REENABLED id=0 ssid="Netgear-Home" Mar 24 08:00:19 volumio-jbl wpa_supplicant[1193]: wlan0: Trying to associate with 6c:cd:d6:5f:1c:01 (SSID='Netgear-Home' freq=2412 MHz) Mar 24 08:00:20 volumio-jbl wpa_supplicant[1193]: wlan0: Associated with 6c:cd:d6:5f:1c:01 Mar 24 08:00:20 volumio-jbl wpa_supplicant[1193]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Mar 24 08:00:20 volumio-jbl wpa_supplicant[1193]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=FR Mar 24 08:00:20 volumio-jbl wpa_supplicant[1193]: wlan0: WPA: Key negotiation completed with 6c:cd:d6:5f:1c:01 [PTK=CCMP GTK=CCMP] Mar 24 08:00:20 volumio-jbl wpa_supplicant[1193]: wlan0: CTRL-EVENT-CONNECTED - Connection to 6c:cd:d6:5f:1c:01 completed [id=0 id_str=] Mar 24 08:00:20 volumio-jbl dhcpcd[797]: wlan0: carrier acquired Mar 24 08:00:20 volumio-jbl dhcpcd[797]: wlan0: IAID eb:87:ea:64 Mar 24 08:00:20 volumio-jbl volumio[30760]: info: Initializing connection to go-librespot Websocket Mar 24 08:00:20 volumio-jbl volumio[30760]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 24 08:00:20 volumio-jbl dhcpcd[797]: wlan0: rebinding lease of 192.168.1.24 Mar 24 08:00:20 volumio-jbl dhcpcd[797]: wlan0: probing address 192.168.1.24/24 Mar 24 08:00:20 volumio-jbl volumio[30760]: info: Received Get System Info Mar 24 08:00:20 volumio-jbl volumio[30760]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 08:00:20 volumio-jbl volumio[30760]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 08:00:20 volumio-jbl volumio[30760]: info: Discovery: Getting this device information Mar 24 08:00:20 volumio-jbl volumio[30760]: info: CoreCommandRouter::volumioGetState Mar 24 08:00:20 volumio-jbl volumio[30760]: info: CorePlayQueue::getTrack 0 Mar 24 08:00:20 volumio-jbl volumio[30760]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 08:00:20 volumio-jbl volumio[30760]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 24 08:00:20 volumio-jbl volumio[30760]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 24 08:00:20 volumio-jbl dhcpcd[797]: wlan0: soliciting an IPv6 router Mar 24 08:00:21 volumio-jbl volumio5-onboarding[2210]: time=2026-03-24T08:00:21.401+01:00 level=INFO msg="service successfully established" component=discovery/localnet Mar 24 08:00:22 volumio-jbl systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 541. Mar 24 08:00:22 volumio-jbl systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 08:00:22 volumio-jbl systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 08:00:22 volumio-jbl go-librespot[6290]: go-librespot daemon starting... Mar 24 08:00:22 volumio-jbl go-librespot[6291]: time="2026-03-24T08:00:22+01:00" level=info msg="running go-librespot 0.6.2" Mar 24 08:00:22 volumio-jbl go-librespot[6291]: time="2026-03-24T08:00:22+01:00" level=debug msg="app state loaded" Mar 24 08:00:22 volumio-jbl go-librespot[6291]: time="2026-03-24T08:00:22+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 08:00:22 volumio-jbl go-librespot[6291]: time="2026-03-24T08:00:22+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 24 08:00:22 volumio-jbl systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 08:00:22 volumio-jbl systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 08:00:23 volumio-jbl volumio[30760]: info: Initializing connection to go-librespot Websocket Mar 24 08:00:23 volumio-jbl volumio[30760]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 24 08:00:25 volumio-jbl dhcpcd[797]: wlan0: leased 192.168.1.24 for 43200 seconds Mar 24 08:00:25 volumio-jbl avahi-daemon[1312]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.24. Mar 24 08:00:25 volumio-jbl dhcpcd[797]: wlan0: adding route to 192.168.1.0/24 Mar 24 08:00:25 volumio-jbl avahi-daemon[1312]: New relevant interface wlan0.IPv4 for mDNS. Mar 24 08:00:25 volumio-jbl dhcpcd[797]: wlan0: adding default route via 192.168.1.254 Mar 24 08:00:25 volumio-jbl avahi-daemon[1312]: Registering new address record for 192.168.1.24 on wlan0.IPv4. Mar 24 08:00:25 volumio-jbl systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. Mar 24 08:00:25 volumio-jbl systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... Mar 24 08:00:25 volumio-jbl systemd[1]: welcome.service: Deactivated successfully. Mar 24 08:00:25 volumio-jbl systemd[1]: Stopped welcome.service - Show a welcome message on console. Mar 24 08:00:25 volumio-jbl systemd[1]: Stopping welcome.service - Show a welcome message on console... Mar 24 08:00:25 volumio-jbl systemd[1]: Starting welcome.service - Show a welcome message on console... Mar 24 08:00:25 volumio-jbl systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 542. Mar 24 08:00:25 volumio-jbl systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 08:00:25 volumio-jbl systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 08:00:25 volumio-jbl go-librespot[6321]: go-librespot daemon starting... Mar 24 08:00:25 volumio-jbl go-librespot[6322]: time="2026-03-24T08:00:25+01:00" level=info msg="running go-librespot 0.6.2" Mar 24 08:00:25 volumio-jbl go-librespot[6322]: time="2026-03-24T08:00:25+01:00" level=debug msg="app state loaded" Mar 24 08:00:25 volumio-jbl welcome[6313]: Resolved ip:[1] 192.168.1.24 Mar 24 08:00:25 volumio-jbl go-librespot[6322]: time="2026-03-24T08:00:25+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 08:00:25 volumio-jbl systemd[1]: Finished welcome.service - Show a welcome message on console. Mar 24 08:00:25 volumio-jbl systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Mar 24 08:00:25 volumio-jbl nmbd[1092]: [2026/03/24 08:00:25.615865, 0] ../../source3/nmbd/nmbd_namequery.c:109(query_name_response) Mar 24 08:00:25 volumio-jbl nmbd[1092]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.1.24 for name WORKGROUP<1d>. Mar 24 08:00:25 volumio-jbl nmbd[1092]: This response was from IP 192.168.1.105, reporting an IP address of 192.168.1.105. Mar 24 08:00:25 volumio-jbl volumio[30760]: info: Received Get System Info Mar 24 08:00:25 volumio-jbl volumio[30760]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 08:00:25 volumio-jbl volumio[30760]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 08:00:25 volumio-jbl volumio[30760]: info: Discovery: Getting this device information Mar 24 08:00:25 volumio-jbl volumio[30760]: info: CoreCommandRouter::volumioGetState Mar 24 08:00:25 volumio-jbl volumio[30760]: info: CorePlayQueue::getTrack 0 Mar 24 08:00:25 volumio-jbl volumio[30760]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 08:00:25 volumio-jbl volumio[30760]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 24 08:00:25 volumio-jbl volumio[30760]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 24 08:00:26 volumio-jbl volumio[30760]: info: Initializing connection to go-librespot Websocket Mar 24 08:00:26 volumio-jbl go-librespot[6322]: time="2026-03-24T08:00:26+01:00" level=debug msg="new websocket client" Mar 24 08:00:26 volumio-jbl volumio[30760]: info: Connection to go-librespot Websocket established Mar 24 08:00:26 volumio-jbl volumio5-onboarding[2210]: time=2026-03-24T08:00:26.444+01:00 level=INFO msg="service successfully established" component=discovery/localnet Mar 24 08:00:26 volumio-jbl volumio[30760]: info: Discovery: this is already registered, 2216369f-bad2-4016-b489-82d02f56aea3 Mar 24 08:00:26 volumio-jbl volumio[30760]: info: Discovery: Found device Volumio JBL Mar 24 08:00:26 volumio-jbl volumio[30760]: info: CoreCommandRouter::volumioGetState Mar 24 08:00:26 volumio-jbl volumio[30760]: info: CorePlayQueue::getTrack 0 Mar 24 08:00:26 volumio-jbl ntpd[922]: IO: Listen normally on 13 wlan0 192.168.1.24:123 Mar 24 08:00:26 volumio-jbl ntpd[922]: IO: new interface(s) found: waking up resolver Mar 24 08:00:28 volumio-jbl volumio[30760]: info: Volumio Network Manager: Network status updated: 2 Mar 24 08:00:29 volumio-jbl volumio[30760]: info: Getting Spotify volume Mar 24 08:00:32 volumio-jbl volumio[30760]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Mar 24 08:00:32 volumio-jbl volumio[30760]: info: CoreCommandRouter::volumioGetState Mar 24 08:00:32 volumio-jbl volumio[30760]: info: CorePlayQueue::getTrack 0 Mar 24 08:00:32 volumio-jbl volumio[30760]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Mar 24 08:00:32 volumio-jbl volumio[30760]: SPOTIFY: SPOTIFY VOLUME undefined Mar 24 08:00:32 volumio-jbl volumio[30760]: SPOTIFY: VOLUMIO VOLUME 55 Mar 24 08:00:32 volumio-jbl volumio[30760]: info: Aligning Spotify Volume to Volumio Volume Mar 24 08:00:32 volumio-jbl volumio[30760]: info: CoreCommandRouter::volumioGetState Mar 24 08:00:32 volumio-jbl volumio[30760]: info: CorePlayQueue::getTrack 0 Mar 24 08:00:32 volumio-jbl volumio[30760]: info: Setting Spotify Volume from Volumio: 55 Mar 24 08:00:34 volumio-jbl volumio[30760]: SPOTIFY: SETTING SPOTIFY VOLUME 55 Mar 24 08:00:34 volumio-jbl volumio[30760]: info: Sending Spotify command with payload to local API: /player/volume Mar 24 08:00:37 volumio-jbl go-librespot[6322]: time="2026-03-24T08:00:37+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 08:00:37 volumio-jbl go-librespot[6322]: time="2026-03-24T08:00:37+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 24 08:00:37 volumio-jbl go-librespot[6322]: time="2026-03-24T08:00:37+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 24 08:00:37 volumio-jbl go-librespot[6322]: time="2026-03-24T08:00:37+01:00" level=info msg="zeroconf server listening on port 36263" Mar 24 08:00:39 volumio-jbl volumio[30760]: info: CoreCommandRouter::volumioGetState Mar 24 08:00:39 volumio-jbl volumio[30760]: info: CorePlayQueue::getTrack 0 Mar 24 08:00:50 volumio-jbl volumio[30760]: info: Listing playlists Mar 24 08:00:50 volumio-jbl volumio[30760]: info: Listing playlists Mar 24 08:00:52 volumio-jbl volumio[30760]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 24 08:00:52 volumio-jbl volumio[30760]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 24 08:00:52 volumio-jbl volumio[30760]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 24 08:00:52 volumio-jbl volumio[30760]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 24 08:00:52 volumio-jbl volumio[30760]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 24 08:00:52 volumio-jbl volumio[30760]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 24 08:00:52 volumio-jbl volumio[30760]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 24 08:00:52 volumio-jbl volumio[30760]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 24 08:00:52 volumio-jbl volumio[30760]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 24 08:00:52 volumio-jbl volumio[30760]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 24 08:00:52 volumio-jbl volumio[30760]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 24 08:00:52 volumio-jbl volumio[30760]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 24 08:00:52 volumio-jbl volumio[30760]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 24 08:00:52 volumio-jbl volumio[30760]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 24 08:00:52 volumio-jbl volumio[30760]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 24 08:00:52 volumio-jbl volumio[30760]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 24 08:00:52 volumio-jbl volumio[30760]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 24 08:00:52 volumio-jbl volumio[30760]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 24 08:00:52 volumio-jbl volumio[30760]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 24 08:00:52 volumio-jbl volumio[30760]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 24 08:00:52 volumio-jbl volumio[30760]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 24 08:00:52 volumio-jbl volumio[30760]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 24 08:00:52 volumio-jbl volumio[30760]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 24 08:00:52 volumio-jbl volumio[30760]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 24 08:00:52 volumio-jbl volumio[30760]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 24 08:00:52 volumio-jbl volumio[30760]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 24 08:00:52 volumio-jbl volumio[30760]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 24 08:00:52 volumio-jbl volumio[30760]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 24 08:00:52 volumio-jbl volumio[30760]: info: Adding plugin bluetooth to MyMusic Plugins Mar 24 08:00:52 volumio-jbl volumio[30760]: info: Adding plugin multiroom to MyMusic Plugins Mar 24 08:00:52 volumio-jbl volumio[30760]: info: Adding plugin metavolumio to MyMusic Plugins Mar 24 08:00:52 volumio-jbl volumio[30760]: info: Adding plugin cd_controller to MyMusic Plugins Mar 24 08:00:52 volumio-jbl volumio[30760]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 24 08:00:52 volumio-jbl volumio[30760]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 24 08:00:52 volumio-jbl volumio[30760]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 24 08:00:52 volumio-jbl volumio[30760]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 24 08:00:54 volumio-jbl volumio[30760]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 24 08:00:54 volumio-jbl volumio[30760]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 24 08:00:54 volumio-jbl volumio[30760]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 08:00:54 volumio-jbl volumio[30760]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 08:00:54 volumio-jbl volumio[30760]: info: Starting MyVolumio Remote Streaming Endpoints Mar 24 08:00:54 volumio-jbl volumio[30760]: info: MyVolumio login type: Token Mar 24 08:00:54 volumio-jbl volumio[30760]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 24 08:00:54 volumio-jbl volumio[30760]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 24 08:00:55 volumio-jbl volumio[30760]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 24 08:00:55 volumio-jbl volumio[30760]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 24 08:00:55 volumio-jbl volumio[30760]: info: Streaming services startup Mar 24 08:00:55 volumio-jbl volumio[30760]: info: Starting Streaming Daemon Mar 24 08:00:55 volumio-jbl volumio[30760]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 24 08:00:55 volumio-jbl sudo[6409]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 24 08:00:55 volumio-jbl sudo[6409]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 08:00:55 volumio-jbl sudo[6409]: pam_unix(sudo:session): session closed for user root Mar 24 08:00:55 volumio-jbl volumio[30760]: error: Cannot start Volumio Streaming Daemon Mar 24 08:00:55 volumio-jbl volumio[30760]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 24 08:00:55 volumio-jbl volumio[30760]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 24 08:00:57 volumio-jbl volumio[30760]: (node:30760) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 close listeners added to [TLSSocket]. Use emitter.setMaxListeners() to increase limit Mar 24 08:00:57 volumio-jbl volumio[30760]: (Use `node --trace-warnings ...` to show where the warning was created) Mar 24 08:00:59 volumio-jbl volumio[30760]: error: MyVolumio Custom Token format not valid, refreshing it Mar 24 08:00:59 volumio-jbl volumio[30760]: info: CoreCommandRouter::volumioGetState Mar 24 08:00:59 volumio-jbl volumio[30760]: info: CorePlayQueue::getTrack 0 Mar 24 08:01:01 volumio-jbl volumio[30760]: info: Listing playlists Mar 24 08:01:01 volumio-jbl volumio[30760]: info: Listing playlists Mar 24 08:01:03 volumio-jbl volumio[30760]: info: MyVolumio login type: Token Mar 24 08:01:07 volumio-jbl go-librespot[6322]: time="2026-03-24T08:01:07+01:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": context deadline exceeded (Client.Timeout exceeded while awaiting headers)" Mar 24 08:01:07 volumio-jbl systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 08:01:07 volumio-jbl systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 08:01:07 volumio-jbl volumio[30760]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Mar 24 08:01:07 volumio-jbl volumio[30760]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 08:01:07 volumio-jbl volumio[30760]: Error: socket hang up Mar 24 08:01:07 volumio-jbl volumio[30760]: at connResetException (node:internal/errors:720:14) Mar 24 08:01:07 volumio-jbl volumio[30760]: at Socket.socketOnEnd (node:_http_client:519:23) Mar 24 08:01:07 volumio-jbl volumio[30760]: at Socket.emit (node:events:526:35) Mar 24 08:01:07 volumio-jbl volumio[30760]: at endReadableNT (node:internal/streams/readable:1376:12) Mar 24 08:01:07 volumio-jbl volumio[30760]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Mar 24 08:01:07 volumio-jbl volumio[30760]: code: 'ECONNRESET', Mar 24 08:01:07 volumio-jbl volumio[30760]: response: undefined Mar 24 08:01:07 volumio-jbl volumio[30760]: } Mar 24 08:01:07 volumio-jbl volumio[30760]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 08:01:08 volumio-jbl sudo[6462]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-24 08:00' Mar 24 08:01:08 volumio-jbl sudo[6462]: 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="dc61260dec5515dafd2b634881860b4c46c919ff" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Mar 6 16:46:58 UTC 2026" VOLUMIO_VERSION="4.103" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="aa741395b8bfc648ff5d04e312f53d2c"