-- Logs begin at Fri 2025-10-17 19:14:23 EEST, end at Fri 2025-10-17 19:18:01 EEST. -- Oct 17 19:17:00 volumio-retina systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 17 19:17:00 volumio-retina systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 39. Oct 17 19:17:00 volumio-retina systemd[1]: Stopped go-librespot Daemon. Oct 17 19:17:00 volumio-retina systemd[1]: Started go-librespot Daemon. Oct 17 19:17:00 volumio-retina go-librespot[2315]: Librespot-go daemon starting... Oct 17 19:17:00 volumio-retina go-librespot[2315]: time="2025-10-17T19:17:00+03:00" level=info msg="generated new device id: e1d270d09d657dffad8c65866b4443c48b3a858c" Oct 17 19:17:00 volumio-retina go-librespot[2315]: time="2025-10-17T19:17:00+03:00" level=fatal msg="failed running zeroconf" 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" Oct 17 19:17:00 volumio-retina systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 17 19:17:00 volumio-retina systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 17 19:17:02 volumio-retina volumio[1157]: info: Initializing connection to go-librespot Websocket Oct 17 19:17:02 volumio-retina volumio[1157]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 17 19:17:03 volumio-retina systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 17 19:17:03 volumio-retina systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 40. Oct 17 19:17:03 volumio-retina systemd[1]: Stopped go-librespot Daemon. Oct 17 19:17:03 volumio-retina systemd[1]: Started go-librespot Daemon. Oct 17 19:17:03 volumio-retina go-librespot[2322]: Librespot-go daemon starting... Oct 17 19:17:03 volumio-retina go-librespot[2322]: time="2025-10-17T19:17:03+03:00" level=info msg="generated new device id: 5e09211babf1a3fc61f67bd2d7e8c8b85d3b96a7" Oct 17 19:17:03 volumio-retina go-librespot[2322]: time="2025-10-17T19:17:03+03:00" level=fatal msg="failed running zeroconf" 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" Oct 17 19:17:03 volumio-retina systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 17 19:17:03 volumio-retina systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 17 19:17:04 volumio-retina kernel: usb 1-5: new full-speed USB device number 4 using xhci_hcd Oct 17 19:17:05 volumio-retina kernel: usb 1-5: New USB device found, idVendor=1997, idProduct=2466, bcdDevice= 1.05 Oct 17 19:17:05 volumio-retina kernel: usb 1-5: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Oct 17 19:17:05 volumio-retina kernel: usb 1-5: Product: Wireless Receiver Oct 17 19:17:05 volumio-retina kernel: usb 1-5: Manufacturer: Telink Oct 17 19:17:05 volumio-retina kernel: input: Telink Wireless Receiver Mouse as /devices/pci0000:00/0000:00:14.0/usb1/1-5/1-5:1.0/0003:1997:2466.0007/input/input18 Oct 17 19:17:05 volumio-retina kernel: input: Telink Wireless Receiver Consumer Control as /devices/pci0000:00/0000:00:14.0/usb1/1-5/1-5:1.0/0003:1997:2466.0007/input/input19 Oct 17 19:17:05 volumio-retina kernel: input: Telink Wireless Receiver System Control as /devices/pci0000:00/0000:00:14.0/usb1/1-5/1-5:1.0/0003:1997:2466.0007/input/input20 Oct 17 19:17:05 volumio-retina kernel: hid-generic 0003:1997:2466.0007: input,hidraw6: USB HID v1.11 Mouse [Telink Wireless Receiver] on usb-0000:00:14.0-5/input0 Oct 17 19:17:05 volumio-retina kernel: input: Telink Wireless Receiver as /devices/pci0000:00/0000:00:14.0/usb1/1-5/1-5:1.1/0003:1997:2466.0008/input/input21 Oct 17 19:17:05 volumio-retina kernel: hid-generic 0003:1997:2466.0008: input,hidraw7: USB HID v1.11 Keyboard [Telink Wireless Receiver] on usb-0000:00:14.0-5/input1 Oct 17 19:17:05 volumio-retina systemd-udevd[2334]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Oct 17 19:17:05 volumio-retina systemd-udevd[2333]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Oct 17 19:17:05 volumio-retina systemd-logind[906]: Watching system buttons on /dev/input/event20 (Telink Wireless Receiver System Control) Oct 17 19:17:05 volumio-retina systemd-udevd[2329]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Oct 17 19:17:05 volumio-retina systemd-udevd[2331]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Oct 17 19:17:05 volumio-retina systemd-logind[906]: Watching system buttons on /dev/input/event21 (Telink Wireless Receiver) Oct 17 19:17:05 volumio-retina systemd-udevd[2332]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Oct 17 19:17:05 volumio-retina systemd-logind[906]: Watching system buttons on /dev/input/event19 (Telink Wireless Receiver Consumer Control) Oct 17 19:17:05 volumio-retina volumio[1157]: info: Initializing connection to go-librespot Websocket Oct 17 19:17:05 volumio-retina volumio[1157]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 17 19:17:06 volumio-retina systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 17 19:17:06 volumio-retina systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 41. Oct 17 19:17:06 volumio-retina systemd[1]: Stopped go-librespot Daemon. Oct 17 19:17:06 volumio-retina systemd[1]: Started go-librespot Daemon. Oct 17 19:17:06 volumio-retina go-librespot[2354]: Librespot-go daemon starting... Oct 17 19:17:06 volumio-retina go-librespot[2354]: time="2025-10-17T19:17:06+03:00" level=info msg="generated new device id: 7b566fb74e71ed94f8bbed9104cbc6088fcf28e8" Oct 17 19:17:06 volumio-retina go-librespot[2354]: time="2025-10-17T19:17:06+03:00" level=fatal msg="failed running zeroconf" 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" Oct 17 19:17:06 volumio-retina systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 17 19:17:06 volumio-retina systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 17 19:17:08 volumio-retina volumio[1157]: info: Initializing connection to go-librespot Websocket Oct 17 19:17:08 volumio-retina volumio[1157]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 17 19:17:09 volumio-retina systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 17 19:17:09 volumio-retina systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 42. Oct 17 19:17:09 volumio-retina systemd[1]: Stopped go-librespot Daemon. Oct 17 19:17:09 volumio-retina systemd[1]: Started go-librespot Daemon. Oct 17 19:17:09 volumio-retina go-librespot[2361]: Librespot-go daemon starting... Oct 17 19:17:09 volumio-retina go-librespot[2361]: time="2025-10-17T19:17:09+03:00" level=info msg="generated new device id: 31084f9eb5b5f064941316796c5870b1d28c5ce6" Oct 17 19:17:09 volumio-retina go-librespot[2361]: time="2025-10-17T19:17:09+03:00" level=fatal msg="failed running zeroconf" 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" Oct 17 19:17:09 volumio-retina systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 17 19:17:09 volumio-retina systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 17 19:17:11 volumio-retina volumio[1157]: info: Initializing connection to go-librespot Websocket Oct 17 19:17:11 volumio-retina volumio[1157]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 17 19:17:13 volumio-retina systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 17 19:17:13 volumio-retina systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 43. Oct 17 19:17:13 volumio-retina systemd[1]: Stopped go-librespot Daemon. Oct 17 19:17:13 volumio-retina systemd[1]: Started go-librespot Daemon. Oct 17 19:17:13 volumio-retina go-librespot[2369]: Librespot-go daemon starting... Oct 17 19:17:13 volumio-retina go-librespot[2369]: time="2025-10-17T19:17:13+03:00" level=info msg="generated new device id: b607b848d5ad2a194bc449d5db719462e6bba6c0" Oct 17 19:17:13 volumio-retina go-librespot[2369]: time="2025-10-17T19:17:13+03:00" level=fatal msg="failed running zeroconf" 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" Oct 17 19:17:13 volumio-retina systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 17 19:17:13 volumio-retina systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 17 19:17:14 volumio-retina volumio[1157]: info: Initializing connection to go-librespot Websocket Oct 17 19:17:14 volumio-retina volumio[1157]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 17 19:17:14 volumio-retina volumio[1157]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 17 19:17:14 volumio-retina volumio[1157]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Oct 17 19:17:14 volumio-retina volumio[1157]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Oct 17 19:17:14 volumio-retina volumio[1157]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Oct 17 19:17:14 volumio-retina volumio[1157]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableUIs Oct 17 19:17:15 volumio-retina volumio[1157]: info: Received Get System Version Oct 17 19:17:15 volumio-retina volumio[1157]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 17 19:17:15 volumio-retina volumio[1157]: info: CoreCommandRouter::executeOnPlugin: appearance , getBackgrounds Oct 17 19:17:16 volumio-retina systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 17 19:17:16 volumio-retina systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 44. Oct 17 19:17:16 volumio-retina systemd[1]: Stopped go-librespot Daemon. Oct 17 19:17:16 volumio-retina systemd[1]: Started go-librespot Daemon. Oct 17 19:17:16 volumio-retina go-librespot[2386]: Librespot-go daemon starting... Oct 17 19:17:16 volumio-retina go-librespot[2386]: time="2025-10-17T19:17:16+03:00" level=info msg="generated new device id: 7a9350d52d7637cfbe784d7380f766b25d78182c" Oct 17 19:17:16 volumio-retina go-librespot[2386]: time="2025-10-17T19:17:16+03:00" level=fatal msg="failed running zeroconf" 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" Oct 17 19:17:16 volumio-retina systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 17 19:17:16 volumio-retina systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 17 19:17:17 volumio-retina volumio[1157]: info: Initializing connection to go-librespot Websocket Oct 17 19:17:17 volumio-retina volumio[1157]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 17 19:17:19 volumio-retina systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 17 19:17:19 volumio-retina systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 45. Oct 17 19:17:19 volumio-retina systemd[1]: Stopped go-librespot Daemon. Oct 17 19:17:19 volumio-retina systemd[1]: Started go-librespot Daemon. Oct 17 19:17:19 volumio-retina go-librespot[2396]: Librespot-go daemon starting... Oct 17 19:17:19 volumio-retina go-librespot[2396]: time="2025-10-17T19:17:19+03:00" level=info msg="generated new device id: f7e56e0b09ea5101ce0ab46d07e7b3ff0b111b45" Oct 17 19:17:19 volumio-retina go-librespot[2396]: time="2025-10-17T19:17:19+03:00" level=fatal msg="failed running zeroconf" 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" Oct 17 19:17:19 volumio-retina systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 17 19:17:19 volumio-retina systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 17 19:17:20 volumio-retina volumio[1157]: info: Initializing connection to go-librespot Websocket Oct 17 19:17:20 volumio-retina volumio[1157]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 17 19:17:22 volumio-retina systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 17 19:17:22 volumio-retina systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 46. Oct 17 19:17:22 volumio-retina systemd[1]: Stopped go-librespot Daemon. Oct 17 19:17:22 volumio-retina systemd[1]: Started go-librespot Daemon. Oct 17 19:17:22 volumio-retina go-librespot[2403]: Librespot-go daemon starting... Oct 17 19:17:22 volumio-retina go-librespot[2403]: time="2025-10-17T19:17:22+03:00" level=info msg="generated new device id: ad4d65bb121695c3cf2c6662b04ecd2834ebcc4d" Oct 17 19:17:22 volumio-retina go-librespot[2403]: time="2025-10-17T19:17:22+03:00" level=fatal msg="failed running zeroconf" 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" Oct 17 19:17:22 volumio-retina systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 17 19:17:22 volumio-retina systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 17 19:17:23 volumio-retina volumio[1157]: info: Initializing connection to go-librespot Websocket Oct 17 19:17:23 volumio-retina volumio[1157]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 17 19:17:23 volumio-retina volumio[1157]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 17 19:17:23 volumio-retina volumio[1157]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Oct 17 19:17:23 volumio-retina volumio[1157]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork Oct 17 19:17:23 volumio-retina sudo[2413]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 Oct 17 19:17:23 volumio-retina sudo[2413]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 17 19:17:23 volumio-retina sudo[2419]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Oct 17 19:17:23 volumio-retina sudo[2419]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 17 19:17:23 volumio-retina sudo[2419]: pam_unix(sudo:session): session closed for user root Oct 17 19:17:23 volumio-retina sudo[2426]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Oct 17 19:17:23 volumio-retina sudo[2426]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 17 19:17:23 volumio-retina sudo[2426]: pam_unix(sudo:session): session closed for user root Oct 17 19:17:23 volumio-retina sudo[2435]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Oct 17 19:17:23 volumio-retina sudo[2435]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 17 19:17:23 volumio-retina sudo[2435]: pam_unix(sudo:session): session closed for user root Oct 17 19:17:23 volumio-retina sudo[2444]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 17 19:17:23 volumio-retina sudo[2444]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 17 19:17:23 volumio-retina volumio[1157]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworksScanCache Oct 17 19:17:23 volumio-retina volumio[1157]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworks Oct 17 19:17:23 volumio-retina sudo[2413]: pam_unix(sudo:session): session closed for user root Oct 17 19:17:23 volumio-retina sudo[2449]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 17 19:17:23 volumio-retina sudo[2449]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 17 19:17:23 volumio-retina sudo[2444]: pam_unix(sudo:session): session closed for user root Oct 17 19:17:23 volumio-retina sudo[2449]: pam_unix(sudo:session): session closed for user root Oct 17 19:17:23 volumio-retina sudo[2457]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Oct 17 19:17:23 volumio-retina sudo[2457]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 17 19:17:24 volumio-retina volumiologrotate[909]: ls: cannot access '/var/log/samba/log.wb-VOLUMIO': No such file or directory Oct 17 19:17:24 volumio-retina volumiologrotate[909]: ls: cannot access 'RETINA': No such file or directory Oct 17 19:17:26 volumio-retina systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 17 19:17:26 volumio-retina systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 47. Oct 17 19:17:26 volumio-retina systemd[1]: Stopped go-librespot Daemon. Oct 17 19:17:26 volumio-retina systemd[1]: Started go-librespot Daemon. Oct 17 19:17:26 volumio-retina go-librespot[2506]: Librespot-go daemon starting... Oct 17 19:17:26 volumio-retina go-librespot[2506]: time="2025-10-17T19:17:26+03:00" level=info msg="generated new device id: 5d3ea8b7ded99a4f93ba6eb5f9b5233634720139" Oct 17 19:17:26 volumio-retina go-librespot[2506]: time="2025-10-17T19:17:26+03:00" level=fatal msg="failed running zeroconf" 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" Oct 17 19:17:26 volumio-retina systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 17 19:17:26 volumio-retina systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 17 19:17:26 volumio-retina volumio[1157]: info: Initializing connection to go-librespot Websocket Oct 17 19:17:26 volumio-retina volumio[1157]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 17 19:17:29 volumio-retina sudo[2457]: pam_unix(sudo:session): session closed for user root Oct 17 19:17:29 volumio-retina systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 17 19:17:29 volumio-retina systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 48. Oct 17 19:17:29 volumio-retina systemd[1]: Stopped go-librespot Daemon. Oct 17 19:17:29 volumio-retina systemd[1]: Started go-librespot Daemon. Oct 17 19:17:29 volumio-retina go-librespot[2513]: Librespot-go daemon starting... Oct 17 19:17:29 volumio-retina go-librespot[2513]: time="2025-10-17T19:17:29+03:00" level=info msg="generated new device id: d28e988d122053a991d461a9cf6f6435a531a83f" Oct 17 19:17:29 volumio-retina go-librespot[2513]: time="2025-10-17T19:17:29+03:00" level=fatal msg="failed running zeroconf" 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" Oct 17 19:17:29 volumio-retina systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 17 19:17:29 volumio-retina systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 17 19:17:29 volumio-retina volumio[1157]: info: Initializing connection to go-librespot Websocket Oct 17 19:17:29 volumio-retina volumio[1157]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 17 19:17:32 volumio-retina systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 17 19:17:32 volumio-retina systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 49. Oct 17 19:17:32 volumio-retina systemd[1]: Stopped go-librespot Daemon. Oct 17 19:17:32 volumio-retina systemd[1]: Started go-librespot Daemon. Oct 17 19:17:32 volumio-retina go-librespot[2520]: Librespot-go daemon starting... Oct 17 19:17:32 volumio-retina go-librespot[2520]: time="2025-10-17T19:17:32+03:00" level=info msg="generated new device id: 446aa209e4a7786170840cdce7b7734e0795b9b5" Oct 17 19:17:32 volumio-retina go-librespot[2520]: time="2025-10-17T19:17:32+03:00" level=fatal msg="failed running zeroconf" 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" Oct 17 19:17:32 volumio-retina systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 17 19:17:32 volumio-retina systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 17 19:17:32 volumio-retina volumio[1157]: info: Initializing connection to go-librespot Websocket Oct 17 19:17:32 volumio-retina volumio[1157]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 17 19:17:35 volumio-retina volumio[1157]: info: Initializing connection to go-librespot Websocket Oct 17 19:17:35 volumio-retina volumio[1157]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 17 19:17:35 volumio-retina systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 17 19:17:35 volumio-retina systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 50. Oct 17 19:17:35 volumio-retina systemd[1]: Stopped go-librespot Daemon. Oct 17 19:17:35 volumio-retina systemd[1]: Started go-librespot Daemon. Oct 17 19:17:35 volumio-retina go-librespot[2529]: Librespot-go daemon starting... Oct 17 19:17:35 volumio-retina go-librespot[2529]: time="2025-10-17T19:17:35+03:00" level=info msg="generated new device id: fc72b4662141f11af164e3a611cfd274e6210017" Oct 17 19:17:35 volumio-retina go-librespot[2529]: time="2025-10-17T19:17:35+03:00" level=fatal msg="failed running zeroconf" 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" Oct 17 19:17:35 volumio-retina systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 17 19:17:35 volumio-retina systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 17 19:17:38 volumio-retina volumio[1157]: info: Initializing connection to go-librespot Websocket Oct 17 19:17:38 volumio-retina volumio[1157]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 17 19:17:39 volumio-retina systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 17 19:17:39 volumio-retina systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 51. Oct 17 19:17:39 volumio-retina systemd[1]: Stopped go-librespot Daemon. Oct 17 19:17:39 volumio-retina systemd[1]: Started go-librespot Daemon. Oct 17 19:17:39 volumio-retina go-librespot[2536]: Librespot-go daemon starting... Oct 17 19:17:39 volumio-retina go-librespot[2536]: time="2025-10-17T19:17:39+03:00" level=info msg="generated new device id: 274f1441dd48993d28324e040da08e8d6e4ac303" Oct 17 19:17:39 volumio-retina go-librespot[2536]: time="2025-10-17T19:17:39+03:00" level=fatal msg="failed running zeroconf" 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" Oct 17 19:17:39 volumio-retina systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 17 19:17:39 volumio-retina systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 17 19:17:39 volumio-retina ntpd[992]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Oct 17 19:17:39 volumio-retina volumio[1157]: info: CoreCommandRouter::executeOnPlugin: network , saveWirelessNetworkSettings Oct 17 19:17:39 volumio-retina volumio[1157]: info: Saving new wireless network Oct 17 19:17:39 volumio-retina sudo[2544]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/wpa_supplicant/wpa_supplicant.conf Oct 17 19:17:39 volumio-retina sudo[2544]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 17 19:17:39 volumio-retina sudo[2544]: pam_unix(sudo:session): session closed for user root Oct 17 19:17:39 volumio-retina volumio[1157]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , onNetworkingRestart Oct 17 19:17:39 volumio-retina volumio[1157]: info: Discovery: Restarting Advertising due to device name change Oct 17 19:17:39 volumio-retina sudo[2547]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart wireless.service Oct 17 19:17:39 volumio-retina sudo[2547]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 17 19:17:39 volumio-retina systemd[1]: Stopping Wireless Services... Oct 17 19:17:39 volumio-retina wpa_supplicant[1093]: nl80211: Failed to open /proc/sys/net/ipv4/conf/p2p-dev-wlan0/drop_unicast_in_l2_multicast: No such file or directory Oct 17 19:17:39 volumio-retina wpa_supplicant[1093]: nl80211: Failed to set IPv4 unicast in multicast filter Oct 17 19:17:39 volumio-retina wpa_supplicant[1093]: nl80211: Failed to open /proc/sys/net/ipv4/conf/p2p-dev-wlan0/drop_unicast_in_l2_multicast: No such file or directory Oct 17 19:17:39 volumio-retina wpa_supplicant[1093]: nl80211: Failed to set IPv4 unicast in multicast filter Oct 17 19:17:39 volumio-retina wpa_supplicant[1093]: nl80211: deinit ifname=p2p-dev-wlan0 disabled_11b_rates=0 Oct 17 19:17:39 volumio-retina wpa_supplicant[1093]: p2p-dev-wlan0: CTRL-EVENT-TERMINATING Oct 17 19:17:39 volumio-retina wpa_supplicant[1093]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0 Oct 17 19:17:40 volumio-retina wpa_supplicant[1093]: wlan0: CTRL-EVENT-TERMINATING Oct 17 19:17:40 volumio-retina systemd[1]: wireless.service: Succeeded. Oct 17 19:17:40 volumio-retina systemd[1]: Stopped Wireless Services. Oct 17 19:17:40 volumio-retina systemd[1]: Starting Wireless Services... Oct 17 19:17:40 volumio-retina wireless.js[2549]: Cleaning previous... Oct 17 19:17:40 volumio-retina sudo[2563]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Oct 17 19:17:40 volumio-retina sudo[2563]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 17 19:17:40 volumio-retina sudo[2563]: pam_unix(sudo:session): session closed for user root Oct 17 19:17:40 volumio-retina sudo[2565]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Oct 17 19:17:40 volumio-retina sudo[2565]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 17 19:17:40 volumio-retina sudo[2565]: pam_unix(sudo:session): session closed for user root Oct 17 19:17:40 volumio-retina wireless.js[2549]: Stopped aP Oct 17 19:17:40 volumio-retina sudo[2572]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Oct 17 19:17:40 volumio-retina sudo[2572]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 17 19:17:40 volumio-retina sudo[2572]: pam_unix(sudo:session): session closed for user root Oct 17 19:17:40 volumio-retina sudo[2574]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Oct 17 19:17:40 volumio-retina sudo[2574]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 17 19:17:40 volumio-retina sudo[2574]: pam_unix(sudo:session): session closed for user root Oct 17 19:17:40 volumio-retina sudo[2581]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Oct 17 19:17:40 volumio-retina sudo[2581]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 17 19:17:40 volumio-retina sudo[2581]: pam_unix(sudo:session): session closed for user root Oct 17 19:17:40 volumio-retina sudo[2583]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Oct 17 19:17:40 volumio-retina sudo[2583]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 17 19:17:41 volumio-retina volumio[1157]: info: Initializing connection to go-librespot Websocket Oct 17 19:17:41 volumio-retina volumio[1157]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 17 19:17:42 volumio-retina ntpd[992]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Oct 17 19:17:42 volumio-retina systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 17 19:17:42 volumio-retina systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 52. Oct 17 19:17:42 volumio-retina systemd[1]: Stopped go-librespot Daemon. Oct 17 19:17:42 volumio-retina systemd[1]: Started go-librespot Daemon. Oct 17 19:17:42 volumio-retina go-librespot[2587]: Librespot-go daemon starting... Oct 17 19:17:42 volumio-retina go-librespot[2587]: time="2025-10-17T19:17:42+03:00" level=info msg="generated new device id: 50a867258bdc6ca0d5654fe0308554f4ba84bee2" Oct 17 19:17:42 volumio-retina go-librespot[2587]: time="2025-10-17T19:17:42+03:00" level=fatal msg="failed running zeroconf" 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" Oct 17 19:17:42 volumio-retina systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 17 19:17:42 volumio-retina systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 17 19:17:42 volumio-retina sudo[2583]: pam_unix(sudo:session): session closed for user root Oct 17 19:17:42 volumio-retina wireless.js[2549]: SETTING APPROPRIATE REG DOMAIN: DE Oct 17 19:17:42 volumio-retina sudo[2595]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Oct 17 19:17:42 volumio-retina sudo[2595]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 17 19:17:42 volumio-retina sudo[2595]: pam_unix(sudo:session): session closed for user root Oct 17 19:17:42 volumio-retina sudo[2597]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set DE Oct 17 19:17:42 volumio-retina sudo[2597]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 17 19:17:42 volumio-retina sudo[2597]: pam_unix(sudo:session): session closed for user root Oct 17 19:17:42 volumio-retina wireless.js[2549]: SUCCESSFULLY SET NEW REGDOMAIN: DE Oct 17 19:17:42 volumio-retina wireless.js[2549]: Start wireless flow Oct 17 19:17:42 volumio-retina wireless.js[2549]: Stopped hotspot (if there).. Oct 17 19:17:42 volumio-retina sudo[2602]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Oct 17 19:17:42 volumio-retina sudo[2602]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 17 19:17:42 volumio-retina sudo[2602]: pam_unix(sudo:session): session closed for user root Oct 17 19:17:42 volumio-retina sudo[2604]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Oct 17 19:17:42 volumio-retina sudo[2604]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 17 19:17:43 volumio-retina sudo[2604]: pam_unix(sudo:session): session closed for user root Oct 17 19:17:43 volumio-retina wireless.js[2549]: DHCP IP Oct 17 19:17:43 volumio-retina wireless.js[2549]: Start ap Oct 17 19:17:43 volumio-retina wpa_supplicant[2606]: Successfully initialized wpa_supplicant Oct 17 19:17:43 volumio-retina sudo[2607]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd Oct 17 19:17:43 volumio-retina sudo[2607]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 17 19:17:43 volumio-retina dhcpcd[2608]: sending commands to master dhcpcd process Oct 17 19:17:43 volumio-retina dhcpcd[936]: control command: /sbin/dhcpcd Oct 17 19:17:43 volumio-retina sudo[2607]: pam_unix(sudo:session): session closed for user root Oct 17 19:17:44 volumio-retina ntpd[992]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Oct 17 19:17:44 volumio-retina wireless.js[2549]: trying... Oct 17 19:17:44 volumio-retina sudo[2613]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 17 19:17:44 volumio-retina sudo[2613]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 17 19:17:44 volumio-retina sudo[2613]: pam_unix(sudo:session): session closed for user root Oct 17 19:17:44 volumio-retina volumio[1157]: info: Discovery: Started advertising with name: Volumio RETINA Oct 17 19:17:44 volumio-retina volumio[1157]: info: Initializing connection to go-librespot Websocket Oct 17 19:17:44 volumio-retina volumio[1157]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 17 19:17:45 volumio-retina wireless.js[2549]: trying... Oct 17 19:17:45 volumio-retina sudo[2617]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 17 19:17:45 volumio-retina sudo[2617]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 17 19:17:45 volumio-retina sudo[2617]: pam_unix(sudo:session): session closed for user root Oct 17 19:17:45 volumio-retina systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 17 19:17:45 volumio-retina systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 53. Oct 17 19:17:45 volumio-retina systemd[1]: Stopped go-librespot Daemon. Oct 17 19:17:45 volumio-retina systemd[1]: Started go-librespot Daemon. Oct 17 19:17:45 volumio-retina go-librespot[2619]: Librespot-go daemon starting... Oct 17 19:17:45 volumio-retina go-librespot[2619]: time="2025-10-17T19:17:45+03:00" level=info msg="generated new device id: 51036947ee7969f57a466d6ba70c51f3b0c164a3" Oct 17 19:17:45 volumio-retina go-librespot[2619]: time="2025-10-17T19:17:45+03:00" level=fatal msg="failed running zeroconf" 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" Oct 17 19:17:45 volumio-retina systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 17 19:17:45 volumio-retina systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 17 19:17:46 volumio-retina ntpd[992]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Oct 17 19:17:46 volumio-retina wpa_supplicant[2611]: wlan0: Trying to associate with SSID 'Dream House 2025' Oct 17 19:17:46 volumio-retina wpa_supplicant[2611]: wlan0: Associated with 00:eb:d8:1d:1e:ef Oct 17 19:17:46 volumio-retina wpa_supplicant[2611]: wlan0: CTRL-EVENT-CONNECTED - Connection to 00:eb:d8:1d:1e:ef completed [id=0 id_str=] Oct 17 19:17:46 volumio-retina dhcpcd[936]: wlan0: carrier acquired Oct 17 19:17:46 volumio-retina wpa_supplicant[2611]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Oct 17 19:17:46 volumio-retina wpa_supplicant[2611]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=DE Oct 17 19:17:46 volumio-retina dhcpcd[936]: DUID 00:04:7d:72:d5:21:fe:aa:58:25:9c:f9:25:13:ff:87:9f:7f Oct 17 19:17:46 volumio-retina dhcpcd[936]: wlan0: IAID 32:a9:ef:ff Oct 17 19:17:46 volumio-retina dhcpcd[936]: wlan0: adding address fe80::aebc:32ff:fea9:efff Oct 17 19:17:46 volumio-retina dhcpcd[936]: ipv6_addaddr1: Permission denied Oct 17 19:17:46 volumio-retina wireless.js[2549]: trying... Oct 17 19:17:46 volumio-retina sudo[2628]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 17 19:17:46 volumio-retina sudo[2628]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 17 19:17:46 volumio-retina sudo[2628]: pam_unix(sudo:session): session closed for user root Oct 17 19:17:46 volumio-retina dhcpcd[936]: wlan0: soliciting a DHCP lease Oct 17 19:17:46 volumio-retina dhcpcd[936]: wlan0: offered 192.168.68.77 from 192.168.68.1 Oct 17 19:17:46 volumio-retina dhcpcd[936]: wlan0: probing address 192.168.68.77/22 Oct 17 19:17:46 volumio-retina dhcpcd[936]: wlan0: soliciting an IPv6 router Oct 17 19:17:47 volumio-retina wireless.js[2549]: trying... Oct 17 19:17:47 volumio-retina sudo[2631]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 17 19:17:47 volumio-retina sudo[2631]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 17 19:17:47 volumio-retina sudo[2631]: pam_unix(sudo:session): session closed for user root Oct 17 19:17:47 volumio-retina volumio[1157]: info: Initializing connection to go-librespot Websocket Oct 17 19:17:47 volumio-retina volumio[1157]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 17 19:17:48 volumio-retina wireless.js[2549]: trying... Oct 17 19:17:48 volumio-retina sudo[2634]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 17 19:17:48 volumio-retina sudo[2634]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 17 19:17:48 volumio-retina sudo[2634]: pam_unix(sudo:session): session closed for user root Oct 17 19:17:48 volumio-retina systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 17 19:17:48 volumio-retina systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 54. Oct 17 19:17:48 volumio-retina systemd[1]: Stopped go-librespot Daemon. Oct 17 19:17:48 volumio-retina systemd[1]: Started go-librespot Daemon. Oct 17 19:17:48 volumio-retina go-librespot[2636]: Librespot-go daemon starting... Oct 17 19:17:48 volumio-retina go-librespot[2636]: time="2025-10-17T19:17:48+03:00" level=info msg="generated new device id: 12158166d04b7815dcd3523cf4488f996195bd20" Oct 17 19:17:48 volumio-retina go-librespot[2636]: time="2025-10-17T19:17:48+03:00" level=fatal msg="failed running zeroconf" 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" Oct 17 19:17:48 volumio-retina systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 17 19:17:48 volumio-retina systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 17 19:17:49 volumio-retina wireless.js[2549]: trying... Oct 17 19:17:49 volumio-retina sudo[2644]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 17 19:17:49 volumio-retina sudo[2644]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 17 19:17:49 volumio-retina sudo[2644]: pam_unix(sudo:session): session closed for user root Oct 17 19:17:50 volumio-retina wireless.js[2549]: trying... Oct 17 19:17:50 volumio-retina sudo[2647]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 17 19:17:50 volumio-retina sudo[2647]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 17 19:17:50 volumio-retina sudo[2647]: pam_unix(sudo:session): session closed for user root Oct 17 19:17:50 volumio-retina volumio[1157]: info: Initializing connection to go-librespot Websocket Oct 17 19:17:50 volumio-retina volumio[1157]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 17 19:17:51 volumio-retina wireless.js[2549]: trying... Oct 17 19:17:51 volumio-retina sudo[2650]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 17 19:17:51 volumio-retina sudo[2650]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 17 19:17:51 volumio-retina sudo[2650]: pam_unix(sudo:session): session closed for user root Oct 17 19:17:52 volumio-retina systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 17 19:17:52 volumio-retina systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 55. Oct 17 19:17:52 volumio-retina systemd[1]: Stopped go-librespot Daemon. Oct 17 19:17:52 volumio-retina systemd[1]: Started go-librespot Daemon. Oct 17 19:17:52 volumio-retina go-librespot[2652]: Librespot-go daemon starting... Oct 17 19:17:52 volumio-retina go-librespot[2652]: time="2025-10-17T19:17:52+03:00" level=info msg="generated new device id: 07ca214459efc46d04d37971b043e9fe3347a91c" Oct 17 19:17:52 volumio-retina go-librespot[2652]: time="2025-10-17T19:17:52+03:00" level=fatal msg="failed running zeroconf" 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" Oct 17 19:17:52 volumio-retina systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 17 19:17:52 volumio-retina systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 17 19:17:52 volumio-retina wireless.js[2549]: trying... Oct 17 19:17:52 volumio-retina sudo[2660]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 17 19:17:52 volumio-retina sudo[2660]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 17 19:17:52 volumio-retina sudo[2660]: pam_unix(sudo:session): session closed for user root Oct 17 19:17:52 volumio-retina dhcpcd[936]: wlan0: leased 192.168.68.77 for 7200 seconds Oct 17 19:17:52 volumio-retina avahi-daemon[915]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.68.77. Oct 17 19:17:52 volumio-retina dhcpcd[936]: wlan0: adding route to 192.168.68.0/22 Oct 17 19:17:52 volumio-retina avahi-daemon[915]: New relevant interface wlan0.IPv4 for mDNS. Oct 17 19:17:52 volumio-retina dhcpcd[936]: wlan0: adding default route via 192.168.68.1 Oct 17 19:17:52 volumio-retina avahi-daemon[915]: Registering new address record for 192.168.68.77 on wlan0.IPv4. Oct 17 19:17:52 volumio-retina kernel: ieee80211 phy0: brcmf_inetaddr_changed: fail to get arp ip table err:-52 Oct 17 19:17:52 volumio-retina ntpd[992]: ntpd exiting on signal 15 (Terminated) Oct 17 19:17:52 volumio-retina systemd[1]: Stopping Network Time Service... Oct 17 19:17:52 volumio-retina systemd[1]: ntp.service: Succeeded. Oct 17 19:17:52 volumio-retina systemd[1]: Stopped Network Time Service. Oct 17 19:17:52 volumio-retina systemd[1]: Starting Network Time Service... Oct 17 19:17:52 volumio-retina ntpd[2694]: ntpd 4.2.8p12@1.3728-o (1): Starting Oct 17 19:17:52 volumio-retina ntpd[2694]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Oct 17 19:17:52 volumio-retina systemd[1]: Started Network Time Service. Oct 17 19:17:52 volumio-retina ntpd[2700]: proto: precision = 0.040 usec (-24) Oct 17 19:17:52 volumio-retina ntpd[2700]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Oct 17 19:17:52 volumio-retina ntpd[2700]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Oct 17 19:17:52 volumio-retina ntpd[2700]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 1025 days ago Oct 17 19:17:52 volumio-retina ntpd[2700]: Listen and drop on 0 v6wildcard [::]:123 Oct 17 19:17:52 volumio-retina ntpd[2700]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Oct 17 19:17:52 volumio-retina ntpd[2700]: Listen normally on 2 lo 127.0.0.1:123 Oct 17 19:17:52 volumio-retina ntpd[2700]: Listen normally on 3 wlan0 192.168.68.77:123 Oct 17 19:17:52 volumio-retina ntpd[2700]: Listening on routing socket on fd #20 for interface updates Oct 17 19:17:52 volumio-retina ntpd[2700]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Oct 17 19:17:52 volumio-retina ntpd[2700]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Oct 17 19:17:52 volumio-retina volumio[1157]: info: Discovery: adding 64bdff75-97d8-4eb1-bb7c-5fa7c5d00ed8 Oct 17 19:17:52 volumio-retina volumio[1157]: info: Discovery: Found device Volumio CM5 Oct 17 19:17:52 volumio-retina volumio[1157]: info: Discovery: Connecting to remote: 192.168.68.60 Oct 17 19:17:52 volumio-retina volumio[1157]: info: Discovery: Connected to remote: 192.168.68.60 Oct 17 19:17:53 volumio-retina volumio[1157]: info: Discovery: adding ad7bb0bf-2ae4-4176-ab27-2e4fa796f7f8 Oct 17 19:17:53 volumio-retina volumio[1157]: info: Discovery: Found device Volumio RETINA Oct 17 19:17:53 volumio-retina volumio[1157]: info: CoreCommandRouter::volumioGetState Oct 17 19:17:53 volumio-retina volumio[1157]: info: CorePlayQueue::getTrack 0 Oct 17 19:17:53 volumio-retina volumio[1157]: verbose: New Socket.io Connection to 192.168.68.77:3000 from 192.168.68.60 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Oct 17 19:17:53 volumio-retina volumio[1157]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 17 19:17:53 volumio-retina volumio[1157]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Oct 17 19:17:53 volumio-retina volumio[1157]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Oct 17 19:17:53 volumio-retina volumio[1157]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Oct 17 19:17:53 volumio-retina volumio[1157]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Oct 17 19:17:53 volumio-retina volumio[1157]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 17 19:17:53 volumio-retina volumio[1157]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 17 19:17:53 volumio-retina volumio[1157]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 17 19:17:53 volumio-retina volumio[1157]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 17 19:17:53 volumio-retina volumio[1157]: info: CoreCommandRouter::volumioGetBrowseSources Oct 17 19:17:53 volumio-retina volumio[1157]: info: CoreCommandRouter::volumioGetBrowseSources Oct 17 19:17:53 volumio-retina volumio[1157]: info: CoreCommandRouter::volumioGetBrowseSources Oct 17 19:17:53 volumio-retina volumio[1157]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Oct 17 19:17:53 volumio-retina volumio[1157]: info: CoreCommandRouter::volumioGetState Oct 17 19:17:53 volumio-retina volumio[1157]: info: CorePlayQueue::getTrack 0 Oct 17 19:17:53 volumio-retina wireless.js[2549]: trying... Oct 17 19:17:53 volumio-retina sudo[2705]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Oct 17 19:17:53 volumio-retina sudo[2705]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 17 19:17:53 volumio-retina sudo[2705]: pam_unix(sudo:session): session closed for user root Oct 17 19:17:53 volumio-retina wireless.js[2549]: Connected to: ----Dream House 2025 Oct 17 19:17:53 volumio-retina wireless.js[2549]: ---- Oct 17 19:17:53 volumio-retina sudo[2708]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 17 19:17:53 volumio-retina sudo[2708]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 17 19:17:53 volumio-retina sudo[2708]: pam_unix(sudo:session): session closed for user root Oct 17 19:17:53 volumio-retina wireless.js[2549]: ... joined AP, wlan0 IPv4 is 192.168.68.77, ipV6 is undefined Oct 17 19:17:53 volumio-retina wireless.js[2549]: It's done! AP Oct 17 19:17:53 volumio-retina systemd[1]: Started Wireless Services. Oct 17 19:17:53 volumio-retina sudo[2547]: pam_unix(sudo:session): session closed for user root Oct 17 19:17:53 volumio-retina volumio[1157]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 17 19:17:53 volumio-retina volumio[1157]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Oct 17 19:17:53 volumio-retina ntpd[2700]: Soliciting pool server 31.14.40.58 Oct 17 19:17:53 volumio-retina volumio[1157]: info: Initializing connection to go-librespot Websocket Oct 17 19:17:53 volumio-retina volumio[1157]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 17 19:17:54 volumio-retina ntpd[2700]: Soliciting pool server 93.190.144.19 Oct 17 19:17:54 volumio-retina ntpd[2700]: Soliciting pool server 93.190.144.3 Oct 17 19:17:55 volumio-retina systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 17 19:17:55 volumio-retina systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 56. Oct 17 19:17:55 volumio-retina systemd[1]: Stopped go-librespot Daemon. Oct 17 19:17:55 volumio-retina systemd[1]: Started go-librespot Daemon. Oct 17 19:17:55 volumio-retina go-librespot[2720]: Librespot-go daemon starting... Oct 17 19:17:55 volumio-retina go-librespot[2720]: time="2025-10-17T19:17:55+03:00" level=info msg="generated new device id: b8efcf529d620174023fcee14142ef6cca0eef85" Oct 17 19:17:55 volumio-retina go-librespot[2720]: time="2025-10-17T19:17:55+03: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]" Oct 17 19:17:55 volumio-retina go-librespot[2720]: time="2025-10-17T19:17:55+03: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]" Oct 17 19:17:55 volumio-retina go-librespot[2720]: time="2025-10-17T19:17:55+03: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]" Oct 17 19:17:55 volumio-retina go-librespot[2720]: time="2025-10-17T19:17:55+03:00" level=debug msg="zeroconf server listening on port 41675" Oct 17 19:17:55 volumio-retina ntpd[2700]: Soliciting pool server 109.102.183.146 Oct 17 19:17:55 volumio-retina ntpd[2700]: Soliciting pool server 86.122.68.21 Oct 17 19:17:55 volumio-retina ntpd[2700]: Soliciting pool server 162.159.200.123 Oct 17 19:17:56 volumio-retina ntpd[2700]: Soliciting pool server 45.134.48.236 Oct 17 19:17:56 volumio-retina ntpd[2700]: Soliciting pool server 185.173.16.132 Oct 17 19:17:56 volumio-retina ntpd[2700]: Soliciting pool server 80.96.41.6 Oct 17 19:17:56 volumio-retina ntpd[2700]: Soliciting pool server 31.14.41.138 Oct 17 19:17:56 volumio-retina volumio[1157]: info: Initializing connection to go-librespot Websocket Oct 17 19:17:56 volumio-retina go-librespot[2720]: time="2025-10-17T19:17:56+03:00" level=debug msg="new websocket client" Oct 17 19:17:56 volumio-retina volumio[1157]: info: Connection to go-librespot Websocket established Oct 17 19:17:57 volumio-retina volumio[1157]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 17 19:17:57 volumio-retina ntpd[2700]: Soliciting pool server 162.159.200.1 Oct 17 19:17:57 volumio-retina ntpd[2700]: Soliciting pool server 86.127.71.168 Oct 17 19:17:57 volumio-retina ntpd[2700]: Soliciting pool server 77.81.64.51 Oct 17 19:17:58 volumio-retina volumio[1157]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Oct 17 19:17:58 volumio-retina volumio[1157]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Oct 17 19:17:58 volumio-retina volumio[1157]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Oct 17 19:17:58 volumio-retina volumio[1157]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Oct 17 19:17:58 volumio-retina volumio[1157]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Oct 17 19:17:58 volumio-retina volumio[1157]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Oct 17 19:17:58 volumio-retina volumio[1157]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Oct 17 19:17:58 volumio-retina volumio[1157]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Oct 17 19:17:58 volumio-retina volumio[1157]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Oct 17 19:17:58 volumio-retina volumio[1157]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Oct 17 19:17:58 volumio-retina volumio[1157]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Oct 17 19:17:58 volumio-retina volumio[1157]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Oct 17 19:17:58 volumio-retina volumio[1157]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Oct 17 19:17:58 volumio-retina volumio[1157]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Oct 17 19:17:58 volumio-retina volumio[1157]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Oct 17 19:17:58 volumio-retina volumio[1157]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Oct 17 19:17:58 volumio-retina volumio[1157]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Oct 17 19:17:58 volumio-retina volumio[1157]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Oct 17 19:17:58 volumio-retina volumio[1157]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Oct 17 19:17:58 volumio-retina volumio[1157]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Oct 17 19:17:58 volumio-retina volumio[1157]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Oct 17 19:17:58 volumio-retina volumio[1157]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Oct 17 19:17:58 volumio-retina volumio[1157]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Oct 17 19:17:58 volumio-retina volumio[1157]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Oct 17 19:17:58 volumio-retina volumio[1157]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Oct 17 19:17:58 volumio-retina volumio[1157]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Oct 17 19:17:58 volumio-retina volumio[1157]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Oct 17 19:17:58 volumio-retina volumio[1157]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Oct 17 19:17:58 volumio-retina volumio[1157]: info: Adding plugin bluetooth to MyMusic Plugins Oct 17 19:17:58 volumio-retina volumio[1157]: info: Adding plugin multiroom to MyMusic Plugins Oct 17 19:17:58 volumio-retina volumio[1157]: info: Adding plugin metavolumio to MyMusic Plugins Oct 17 19:17:58 volumio-retina volumio[1157]: info: Adding plugin cd_controller to MyMusic Plugins Oct 17 19:17:58 volumio-retina volumio[1157]: info: Adding plugin smart_inputs to MyMusic Plugins Oct 17 19:17:58 volumio-retina volumio[1157]: info: Adding plugin tidalconnect to MyMusic Plugins Oct 17 19:17:58 volumio-retina volumio[1157]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Oct 17 19:17:58 volumio-retina ntpd[2700]: Soliciting pool server 89.36.93.9 Oct 17 19:17:58 volumio-retina ntpd[2700]: Soliciting pool server 188.241.240.156 Oct 17 19:17:58 volumio-retina volumio[1157]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Oct 17 19:17:58 volumio-retina volumio[1157]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Oct 17 19:17:58 volumio-retina volumio[1157]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 17 19:17:58 volumio-retina volumio[1157]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 17 19:17:58 volumio-retina volumio[1157]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 17 19:17:58 volumio-retina volumio[1157]: info: Starting MyVolumio Remote Streaming Endpoints Oct 17 19:17:58 volumio-retina volumio[1157]: info: MyVolumio login type: Token Oct 17 19:17:58 volumio-retina volumio[1157]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Oct 17 19:17:58 volumio-retina volumio[1157]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Oct 17 19:17:59 volumio-retina volumio[1157]: info: Starting Streaming Service Transparent Proxy Oct 17 19:17:59 volumio-retina volumio[1157]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Oct 17 19:17:59 volumio-retina volumio[1157]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Oct 17 19:17:59 volumio-retina volumio[1157]: info: Streaming services startup Oct 17 19:17:59 volumio-retina volumio[1157]: info: Starting Streaming Daemon Oct 17 19:17:59 volumio-retina sudo[2740]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 17 19:17:59 volumio-retina sudo[2740]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 17 19:17:59 volumio-retina sudo[2740]: pam_unix(sudo:session): session closed for user root Oct 17 19:17:59 volumio-retina volumio[1157]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Oct 17 19:17:59 volumio-retina volumio[1157]: info: CoreCommandRouter::executeOnPlugin: wizard , reportWirelessConnection Oct 17 19:17:59 volumio-retina volumio[1157]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessInfo Oct 17 19:17:59 volumio-retina sudo[2748]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 17 19:17:59 volumio-retina sudo[2748]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 17 19:17:59 volumio-retina sudo[2748]: pam_unix(sudo:session): session closed for user root Oct 17 19:17:59 volumio-retina volumio[1157]: error: Cannot start Volumio Streaming Daemon Oct 17 19:17:59 volumio-retina volumio[1157]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 17 19:17:59 volumio-retina volumio[1157]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 17 19:17:59 volumio-retina sudo[2751]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Oct 17 19:17:59 volumio-retina sudo[2751]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 17 19:17:59 volumio-retina sudo[2751]: pam_unix(sudo:session): session closed for user root Oct 17 19:17:59 volumio-retina volumio[1157]: STREAMING PROXY: Starting server on port 3245 Oct 17 19:17:59 volumio-retina volumio[1157]: Node JS runtime: 14 Oct 17 19:17:59 volumio-retina volumio[1157]: error: MyVolumio Custom Token format not valid, refreshing it Oct 17 19:17:59 volumio-retina ntpd[2700]: Soliciting pool server 193.226.12.21 Oct 17 19:17:59 volumio-retina ntpd[2700]: Soliciting pool server 2606:4700:f1::123 Oct 17 19:17:59 volumio-retina volumio[1157]: info: Getting Spotify volume Oct 17 19:17:59 volumio-retina volumio[1157]: 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 17 19:17:59 volumio-retina volumio[1157]: info: CoreCommandRouter::volumioGetState Oct 17 19:17:59 volumio-retina volumio[1157]: info: CorePlayQueue::getTrack 0 Oct 17 19:17:59 volumio-retina volumio[1157]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Oct 17 19:17:59 volumio-retina volumio[1157]: SPOTIFY: SPOTIFY VOLUME undefined Oct 17 19:17:59 volumio-retina volumio[1157]: SPOTIFY: VOLUMIO VOLUME 35 Oct 17 19:17:59 volumio-retina volumio[1157]: info: Aligning Spotify Volume to Volumio Volume Oct 17 19:17:59 volumio-retina volumio[1157]: info: CoreCommandRouter::volumioGetState Oct 17 19:17:59 volumio-retina volumio[1157]: info: CorePlayQueue::getTrack 0 Oct 17 19:17:59 volumio-retina volumio[1157]: info: Setting Spotify Volume from Volumio: 35 Oct 17 19:18:00 volumio-retina volumio[1157]: info: MyVolumio login type: Token Oct 17 19:18:00 volumio-retina volumio[1157]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Oct 17 19:18:00 volumio-retina volumio[1157]: info: MyVolumio token set successfully Oct 17 19:18:00 volumio-retina volumio[1157]: info: MYVOLUMIO: Adding device Oct 17 19:18:00 volumio-retina volumio[1157]: info: MYVOLUMIO: Evaluating Server Oct 17 19:18:01 volumio-retina volumio[1157]: info: MyVolumio Plan changed: premium Oct 17 19:18:01 volumio-retina volumio[1157]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Oct 17 19:18:01 volumio-retina volumio[1157]: info: Removing browser output: myVolumio user plan is not superstar Oct 17 19:18:01 volumio-retina volumio[1157]: info: Removing audio output: Oct 17 19:18:01 volumio-retina volumio[1157]: info: MYVOLUMIO: Adding device Oct 17 19:18:01 volumio-retina volumio[1157]: info: MYVOLUMIO: Evaluating Server Oct 17 19:18:01 volumio-retina volumio[1157]: info: Remote config written successfully Oct 17 19:18:01 volumio-retina volumio[1157]: info: Starting Tunnel 1 Oct 17 19:18:01 volumio-retina volumio[1157]: info: Starting Tunnel Connection Checker Oct 17 19:18:01 volumio-retina volumio[1157]: SPOTIFY: SETTING SPOTIFY VOLUME 35 Oct 17 19:18:01 volumio-retina volumio[1157]: info: Sending Spotify command with payload to local API: /player/volume Oct 17 19:18:01 volumio-retina volumio[1157]: info: MYVolumio Device disabled Oct 17 19:18:01 volumio-retina volumio[1157]: info: MyVolumio status changed Oct 17 19:18:01 volumio-retina volumio[1157]: info: Streaming services startup Oct 17 19:18:01 volumio-retina volumio[1157]: info: Starting Streaming Daemon Oct 17 19:18:01 volumio-retina sudo[2788]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 17 19:18:01 volumio-retina sudo[2788]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 17 19:18:01 volumio-retina sudo[2788]: pam_unix(sudo:session): session closed for user root Oct 17 19:18:01 volumio-retina volumio[1157]: error: Cannot start Volumio Streaming Daemon Oct 17 19:18:01 volumio-retina volumio[1157]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 17 19:18:01 volumio-retina volumio[1157]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 17 19:18:01 volumio-retina volumio[1157]: info: Setting Geolocation for MyVolumio to eu7 Oct 17 19:18:01 volumio-retina volumio[1157]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 17 19:18:01 volumio-retina volumio[1157]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 17 19:18:01 volumio-retina volumio[1157]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 17 19:18:01 volumio-retina volumio[1157]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 17 19:18:01 volumio-retina volumio[1157]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 17 19:18:01 volumio-retina ntpd[2700]: receive: Unexpected origin timestamp 0xec9ceab9.b3467cf7 does not match aorg 0000000000.00000000 from server@185.173.16.132 xmt 0xec9ceab9.5ae340ae Oct 17 19:18:01 volumio-retina ntpd[2700]: receive: Unexpected origin timestamp 0xec9ceab9.b3451949 does not match aorg 0000000000.00000000 from server@162.159.200.1 xmt 0xec9ceab9.5b648650 Oct 17 19:18:01 volumio-retina volumio[1157]: error: Failed to ping endpoint au1.myvolumio.org : unknown error Oct 17 19:18:01 volumio-retina volumio[1157]: info: Setting Geolocation for MyVolumio to eu7 Oct 17 19:18:01 volumio-retina volumio[1157]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 17 19:18:01 volumio-retina volumio[1157]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 17 19:18:01 volumio-retina volumio[1157]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 17 19:18:01 volumio-retina volumio[1157]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 17 19:18:01 volumio-retina volumio[1157]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 17 19:18:01 volumio-retina volumio[1157]: Error: Unable to resolve or reject the same promise twice Oct 17 19:18:01 volumio-retina volumio[1157]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Oct 17 19:18:01 volumio-retina volumio[1157]: at Socket. (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:32086) Oct 17 19:18:01 volumio-retina volumio[1157]: at Socket.emit (events.js:412:35) Oct 17 19:18:01 volumio-retina volumio[1157]: at endReadableNT (internal/streams/readable.js:1333:12) Oct 17 19:18:01 volumio-retina volumio[1157]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Oct 17 19:18:01 volumio-retina volumio[1157]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 17 19:18:01 volumio-retina ntpd[2700]: receive: Unexpected origin timestamp 0xec9ceab9.b3460590 does not match aorg 0000000000.00000000 from server@45.134.48.236 xmt 0xec9ceab9.5bd0a5d0 Oct 17 19:18:01 volumio-retina sudo[2800]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-10-17 19:17 Oct 17 19:18:01 volumio-retina sudo[2800]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="bba9e3185e150dd0995f9a49355b34fc6218d5a2" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8aa57e3ae5b742ea1069404608336a9884ccfb4e" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 17 Sep 2024 05:33:09 PM CEST" VOLUMIO_VERSION="3.757" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="ee834e1c2a28de3c5d8c48611ecf1167"