-- Logs begin at Sun 2025-06-01 17:58:19 CEST, end at Mon 2025-06-02 03:02:00 CEST. -- Jun 02 03:01:00 czerwone-drzwi ntpd[793]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Jun 02 03:01:06 czerwone-drzwi go-librespot[28245]: time="2025-06-02T03:01:06+02: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\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Jun 02 03:01:06 czerwone-drzwi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 02 03:01:06 czerwone-drzwi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 02 03:01:06 czerwone-drzwi volumio[984]: (node:984) UnhandledPromiseRejectionWarning: Error: socket hang up Jun 02 03:01:06 czerwone-drzwi volumio[984]: at connResetException (internal/errors.js:607:14) Jun 02 03:01:06 czerwone-drzwi volumio[984]: at Socket.socketOnEnd (_http_client.js:493:23) Jun 02 03:01:06 czerwone-drzwi volumio[984]: at Socket.emit (events.js:327:22) Jun 02 03:01:06 czerwone-drzwi volumio[984]: at endReadableNT (internal/streams/readable.js:1327:12) Jun 02 03:01:06 czerwone-drzwi volumio[984]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Jun 02 03:01:06 czerwone-drzwi volumio[984]: (node:984) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 14136) Jun 02 03:01:06 czerwone-drzwi volumio[984]: info: Connection to go-librespot Websocket closed Jun 02 03:01:09 czerwone-drzwi volumio[984]: info: Initializing connection to go-librespot Websocket Jun 02 03:01:09 czerwone-drzwi volumio[984]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 02 03:01:09 czerwone-drzwi systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 02 03:01:09 czerwone-drzwi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12251. Jun 02 03:01:09 czerwone-drzwi systemd[1]: Stopped go-librespot Daemon. Jun 02 03:01:09 czerwone-drzwi systemd[1]: Started go-librespot Daemon. Jun 02 03:01:09 czerwone-drzwi go-librespot[28296]: Librespot-go daemon starting... Jun 02 03:01:09 czerwone-drzwi go-librespot[28296]: time="2025-06-02T03:01:09+02:00" level=info msg="generated new device id: d8922be0e6c1c7eb9c39f61fc742f72e6c38e2a3" Jun 02 03:01:09 czerwone-drzwi go-librespot[28296]: time="2025-06-02T03:01:09+02:00" level=debug msg="stored credentials found for 1177376820" Jun 02 03:01:12 czerwone-drzwi volumio[984]: info: Initializing connection to go-librespot Websocket Jun 02 03:01:12 czerwone-drzwi go-librespot[28296]: time="2025-06-02T03:01:12+02:00" level=debug msg="new websocket client" Jun 02 03:01:12 czerwone-drzwi volumio[984]: info: Connection to go-librespot Websocket established Jun 02 03:01:15 czerwone-drzwi volumio[984]: info: Getting Spotify volume Jun 02 03:01:15 czerwone-drzwi volumio[984]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Jun 02 03:01:15 czerwone-drzwi volumio[984]: info: CoreCommandRouter::volumioGetState Jun 02 03:01:15 czerwone-drzwi volumio[984]: SPOTIFY: RECEIVED VOLUMIO VOLUME 71 Jun 02 03:01:20 czerwone-drzwi ntpd[793]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Jun 02 03:01:29 czerwone-drzwi go-librespot[28296]: time="2025-06-02T03:01:29+02: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\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Jun 02 03:01:29 czerwone-drzwi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 02 03:01:29 czerwone-drzwi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 02 03:01:29 czerwone-drzwi volumio[984]: (node:984) UnhandledPromiseRejectionWarning: Error: socket hang up Jun 02 03:01:29 czerwone-drzwi volumio[984]: at connResetException (internal/errors.js:607:14) Jun 02 03:01:29 czerwone-drzwi volumio[984]: at Socket.socketOnEnd (_http_client.js:493:23) Jun 02 03:01:29 czerwone-drzwi volumio[984]: at Socket.emit (events.js:327:22) Jun 02 03:01:29 czerwone-drzwi volumio[984]: at endReadableNT (internal/streams/readable.js:1327:12) Jun 02 03:01:29 czerwone-drzwi volumio[984]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Jun 02 03:01:29 czerwone-drzwi volumio[984]: (node:984) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 14137) Jun 02 03:01:29 czerwone-drzwi volumio[984]: info: Connection to go-librespot Websocket closed Jun 02 03:01:32 czerwone-drzwi volumio[984]: info: Initializing connection to go-librespot Websocket Jun 02 03:01:32 czerwone-drzwi volumio[984]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 02 03:01:32 czerwone-drzwi systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 02 03:01:32 czerwone-drzwi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12252. Jun 02 03:01:32 czerwone-drzwi systemd[1]: Stopped go-librespot Daemon. Jun 02 03:01:32 czerwone-drzwi systemd[1]: Started go-librespot Daemon. Jun 02 03:01:32 czerwone-drzwi go-librespot[28305]: Librespot-go daemon starting... Jun 02 03:01:32 czerwone-drzwi go-librespot[28305]: time="2025-06-02T03:01:32+02:00" level=info msg="generated new device id: 5c9b9e5aeb8e93b79868fadb2b495d920c00e3ac" Jun 02 03:01:32 czerwone-drzwi go-librespot[28305]: time="2025-06-02T03:01:32+02:00" level=debug msg="stored credentials found for 1177376820" Jun 02 03:01:35 czerwone-drzwi volumio[984]: info: Initializing connection to go-librespot Websocket Jun 02 03:01:35 czerwone-drzwi volumio[984]: info: Connection to go-librespot Websocket established Jun 02 03:01:35 czerwone-drzwi go-librespot[28305]: time="2025-06-02T03:01:35+02:00" level=debug msg="new websocket client" Jun 02 03:01:38 czerwone-drzwi volumio[984]: info: Getting Spotify volume Jun 02 03:01:38 czerwone-drzwi volumio[984]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Jun 02 03:01:38 czerwone-drzwi volumio[984]: info: CoreCommandRouter::volumioGetState Jun 02 03:01:38 czerwone-drzwi volumio[984]: SPOTIFY: RECEIVED VOLUMIO VOLUME 71 Jun 02 03:01:40 czerwone-drzwi ntpd[793]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Jun 02 03:01:48 czerwone-drzwi volumiologrotate[647]: ls: cannot access '/var/log/samba/log.wb-CZERWONE': No such file or directory Jun 02 03:01:48 czerwone-drzwi volumiologrotate[647]: ls: cannot access 'DRZWI': No such file or directory Jun 02 03:01:51 czerwone-drzwi dhcpcd[894]: wlan0: offered 192.168.1.219 from 192.168.1.1 Jun 02 03:01:51 czerwone-drzwi dhcpcd[894]: wlan0: probing address 192.168.1.219/24 Jun 02 03:01:52 czerwone-drzwi go-librespot[28305]: time="2025-06-02T03:01:52+02: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\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Jun 02 03:01:52 czerwone-drzwi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 02 03:01:52 czerwone-drzwi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 02 03:01:52 czerwone-drzwi volumio[984]: (node:984) UnhandledPromiseRejectionWarning: Error: socket hang up Jun 02 03:01:52 czerwone-drzwi volumio[984]: at connResetException (internal/errors.js:607:14) Jun 02 03:01:52 czerwone-drzwi volumio[984]: at Socket.socketOnEnd (_http_client.js:493:23) Jun 02 03:01:52 czerwone-drzwi volumio[984]: at Socket.emit (events.js:327:22) Jun 02 03:01:52 czerwone-drzwi volumio[984]: at endReadableNT (internal/streams/readable.js:1327:12) Jun 02 03:01:52 czerwone-drzwi volumio[984]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Jun 02 03:01:52 czerwone-drzwi volumio[984]: (node:984) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 14138) Jun 02 03:01:52 czerwone-drzwi volumio[984]: info: Connection to go-librespot Websocket closed Jun 02 03:01:55 czerwone-drzwi volumio[984]: info: Initializing connection to go-librespot Websocket Jun 02 03:01:55 czerwone-drzwi systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 02 03:01:55 czerwone-drzwi systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12253. Jun 02 03:01:55 czerwone-drzwi systemd[1]: Stopped go-librespot Daemon. Jun 02 03:01:55 czerwone-drzwi systemd[1]: Started go-librespot Daemon. Jun 02 03:01:55 czerwone-drzwi go-librespot[28356]: Librespot-go daemon starting... Jun 02 03:01:55 czerwone-drzwi go-librespot[28356]: time="2025-06-02T03:01:55+02:00" level=info msg="generated new device id: bf4500d78c317e87bf8367eb98f4466ef748fe68" Jun 02 03:01:55 czerwone-drzwi go-librespot[28356]: time="2025-06-02T03:01:55+02:00" level=debug msg="stored credentials found for 1177376820" Jun 02 03:01:57 czerwone-drzwi dhcpcd[894]: wlan0: leased 192.168.1.219 for 86400 seconds Jun 02 03:01:57 czerwone-drzwi avahi-daemon[639]: Registering new address record for 192.168.1.219 on wlan0.IPv4. Jun 02 03:01:57 czerwone-drzwi dhcpcd[894]: wlan0: adding route to 192.168.1.0/24 Jun 02 03:01:57 czerwone-drzwi dhcpcd[894]: wlan0: changing default route via 192.168.1.1 Jun 02 03:01:57 czerwone-drzwi avahi-daemon[639]: Withdrawing address record for 169.254.91.70 on wlan0. Jun 02 03:01:57 czerwone-drzwi avahi-daemon[639]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 169.254.91.70. Jun 02 03:01:57 czerwone-drzwi avahi-daemon[639]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.219. Jun 02 03:01:57 czerwone-drzwi dhcpcd[894]: wlan0: deleting route to 169.254.0.0/16 Jun 02 03:01:57 czerwone-drzwi dhcpcd[894]: wlan0: pid 894 deleted default route via 192.168.1.1 Jun 02 03:01:58 czerwone-drzwi ntpd[793]: Listen normally on 6 wlan0 192.168.1.219:123 Jun 02 03:01:58 czerwone-drzwi ntpd[793]: Deleting interface #5 wlan0, 169.254.91.70#123, interface stats: received=0, sent=288, dropped=0, active_time=17994 secs Jun 02 03:01:58 czerwone-drzwi ntpd[793]: 193.70.94.182 local addr 169.254.91.70 -> Jun 02 03:01:58 czerwone-drzwi ntpd[793]: 212.127.95.218 local addr 169.254.91.70 -> Jun 02 03:01:58 czerwone-drzwi ntpd[793]: 94.154.96.7 local addr 169.254.91.70 -> Jun 02 03:01:58 czerwone-drzwi ntpd[793]: 162.159.200.123 local addr 169.254.91.70 -> Jun 02 03:01:58 czerwone-drzwi ntpd[793]: 89.161.47.131 local addr 169.254.91.70 -> Jun 02 03:01:58 czerwone-drzwi ntpd[793]: 176.32.165.145 local addr 169.254.91.70 -> Jun 02 03:01:58 czerwone-drzwi ntpd[793]: new interface(s) found: waking up resolver Jun 02 03:01:59 czerwone-drzwi go-librespot[28356]: time="2025-06-02T03:01:59+02:00" level=debug msg="new websocket client" Jun 02 03:01:59 czerwone-drzwi volumio[984]: info: Connection to go-librespot Websocket established Jun 02 03:02:00 czerwone-drzwi volumio[984]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 02 03:02:00 czerwone-drzwi volumio[984]: [t [Error]: A network error (such as timeout, interrupted connection or unreachable host) has occurred.] { Jun 02 03:02:00 czerwone-drzwi volumio[984]: code: 'auth/network-request-failed', Jun 02 03:02:00 czerwone-drzwi volumio[984]: a: null Jun 02 03:02:00 czerwone-drzwi volumio[984]: } Jun 02 03:02:00 czerwone-drzwi volumio[984]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 02 03:02:00 czerwone-drzwi sudo[28411]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-06-02 03:01 Jun 02 03:02:00 czerwone-drzwi sudo[28411]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster 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="4b122b2365bb8c09786cd63b50d1ea6db780eb4e" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="49f98390f2d84c6549f33dc85b694fbd99e4c720" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 04 Jun 2024 08:41:12 PM CEST" VOLUMIO_VERSION="3.703" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="8e78a6e3f56f1bcbbd1760812129a8e9"