-- Logs begin at Thu 2019-02-14 10:11:59 WET, end at Sat 2025-12-13 16:25:04 WET. -- Dec 13 16:24:00 volumio ntpd[807]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Dec 13 16:24:01 volumio volumio[924]: info: Initializing connection to go-librespot Websocket Dec 13 16:24:01 volumio volumio[924]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 13 16:24:01 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 13 16:24:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Dec 13 16:24:01 volumio systemd[1]: Stopped go-librespot Daemon. Dec 13 16:24:01 volumio systemd[1]: Started go-librespot Daemon. Dec 13 16:24:01 volumio go-librespot[15068]: go-librespot daemon starting... Dec 13 16:24:01 volumio go-librespot[15068]: time="2025-12-13T16:24:01Z" level=info msg="running go-librespot 0.4.0" Dec 13 16:24:01 volumio go-librespot[15068]: time="2025-12-13T16:24:01Z" level=debug msg="app state loaded" Dec 13 16:24:01 volumio go-librespot[15068]: time="2025-12-13T16:24:01Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 13 16:24:04 volumio volumio[924]: info: Initializing connection to go-librespot Websocket Dec 13 16:24:04 volumio go-librespot[15068]: time="2025-12-13T16:24:04Z" level=debug msg="new websocket client" Dec 13 16:24:04 volumio volumio[924]: info: Connection to go-librespot Websocket established Dec 13 16:24:06 volumio dhcpcd[685]: eth0: carrier lost Dec 13 16:24:06 volumio kernel: smsc95xx 1-1.1:1.0 eth0: Link is Down Dec 13 16:24:06 volumio ifplugd(eth0)[818]: Link beat lost. Dec 13 16:24:07 volumio volumio[924]: info: Getting Spotify volume Dec 13 16:24:07 volumio volumio[924]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Dec 13 16:24:07 volumio volumio[924]: info: CoreCommandRouter::volumioGetState Dec 13 16:24:07 volumio volumio[924]: info: CorePlayQueue::getTrack 5 Dec 13 16:24:09 volumio dhcpcd[685]: eth0: carrier acquired Dec 13 16:24:09 volumio dhcpcd[685]: eth0: IAID eb:49:c5:34 Dec 13 16:24:09 volumio dhcpcd[685]: eth0: probing address 192.168.1.171/24 Dec 13 16:24:09 volumio kernel: smsc95xx 1-1.1:1.0 eth0: Link is Up - 100Mbps/Full - flow control off Dec 13 16:24:09 volumio ifplugd(eth0)[818]: Link beat detected. Dec 13 16:24:09 volumio dhcpcd[685]: eth0: soliciting an IPv6 router Dec 13 16:24:15 volumio dhcpcd[685]: eth0: using static address 192.168.1.171/24 Dec 13 16:24:15 volumio dhcpcd[685]: eth0: adding route to 192.168.1.0/24 Dec 13 16:24:15 volumio dhcpcd[685]: eth0: adding default route via 192.168.1.1 Dec 13 16:24:15 volumio avahi-daemon[605]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.1.171. Dec 13 16:24:15 volumio avahi-daemon[605]: New relevant interface eth0.IPv4 for mDNS. Dec 13 16:24:15 volumio avahi-daemon[605]: Registering new address record for 192.168.1.171 on eth0.IPv4. Dec 13 16:24:15 volumio dnsmasq[914]: reading /etc/resolv.conf Dec 13 16:24:15 volumio dnsmasq[914]: using nameserver 192.168.1.1#53 Dec 13 16:24:15 volumio dnsmasq[914]: using nameserver 208.67.222.222#53 Dec 13 16:24:15 volumio dnsmasq[914]: using nameserver 208.67.222.222#53 Dec 13 16:24:15 volumio dnsmasq[914]: using nameserver 208.67.220.220#53 Dec 13 16:24:16 volumio ntpd[807]: Listen normally on 7 eth0 192.168.1.171:123 Dec 13 16:24:16 volumio ntpd[807]: 185.134.42.7 local addr 192.168.1.172 -> 192.168.1.171 Dec 13 16:24:16 volumio ntpd[807]: 208.85.20.220 local addr 192.168.1.172 -> 192.168.1.171 Dec 13 16:24:16 volumio ntpd[807]: 84.77.195.114 local addr 192.168.1.172 -> 192.168.1.171 Dec 13 16:24:16 volumio ntpd[807]: 93.176.191.241 local addr 192.168.1.172 -> 192.168.1.171 Dec 13 16:24:16 volumio ntpd[807]: 82.165.173.235 local addr 192.168.1.172 -> 192.168.1.171 Dec 13 16:24:16 volumio ntpd[807]: 195.95.153.43 local addr 192.168.1.172 -> 192.168.1.171 Dec 13 16:24:16 volumio ntpd[807]: new interface(s) found: waking up resolver Dec 13 16:24:17 volumio kernel: CIFS: VFS: \\192.168.1.92 has not responded in 180 seconds. Reconnecting... Dec 13 16:24:18 volumio volumio[924]: info: Volumio Network Manager: Network status updated: 1 Dec 13 16:24:28 volumio ntpd[807]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Dec 13 16:24:29 volumio go-librespot[15068]: time="2025-12-13T16:24:29Z" 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" Dec 13 16:24:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 13 16:24:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 13 16:24:29 volumio volumio[924]: (node:924) UnhandledPromiseRejectionWarning: Error: socket hang up Dec 13 16:24:29 volumio volumio[924]: at connResetException (internal/errors.js:607:14) Dec 13 16:24:29 volumio volumio[924]: at Socket.socketOnEnd (_http_client.js:493:23) Dec 13 16:24:29 volumio volumio[924]: at Socket.emit (events.js:327:22) Dec 13 16:24:29 volumio volumio[924]: at endReadableNT (internal/streams/readable.js:1327:12) Dec 13 16:24:29 volumio volumio[924]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Dec 13 16:24:29 volumio volumio[924]: (node:924) 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: 37) Dec 13 16:24:29 volumio volumio[924]: info: Connection to go-librespot Websocket closed Dec 13 16:24:32 volumio volumio[924]: info: Initializing connection to go-librespot Websocket Dec 13 16:24:32 volumio volumio[924]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 13 16:24:33 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 13 16:24:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Dec 13 16:24:33 volumio systemd[1]: Stopped go-librespot Daemon. Dec 13 16:24:33 volumio systemd[1]: Started go-librespot Daemon. Dec 13 16:24:33 volumio go-librespot[15196]: go-librespot daemon starting... Dec 13 16:24:33 volumio go-librespot[15196]: time="2025-12-13T16:24:33Z" level=info msg="running go-librespot 0.4.0" Dec 13 16:24:33 volumio go-librespot[15196]: time="2025-12-13T16:24:33Z" level=debug msg="app state loaded" Dec 13 16:24:33 volumio go-librespot[15196]: time="2025-12-13T16:24:33Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 13 16:24:35 volumio volumio[924]: info: Initializing connection to go-librespot Websocket Dec 13 16:24:35 volumio go-librespot[15196]: time="2025-12-13T16:24:35Z" level=debug msg="new websocket client" Dec 13 16:24:35 volumio volumio[924]: info: Connection to go-librespot Websocket established Dec 13 16:24:38 volumio volumio[924]: info: Getting Spotify volume Dec 13 16:24:38 volumio volumio[924]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Dec 13 16:24:39 volumio volumio[924]: info: CoreCommandRouter::volumioGetState Dec 13 16:24:39 volumio volumio[924]: info: CorePlayQueue::getTrack 5 Dec 13 16:24:39 volumio sudo[15219]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 13 16:24:39 volumio sudo[15219]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 16:24:39 volumio sudo[15219]: pam_unix(sudo:session): session closed for user root Dec 13 16:24:39 volumio sudo[15221]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 13 16:24:39 volumio sudo[15221]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 16:24:39 volumio sudo[15221]: pam_unix(sudo:session): session closed for user root Dec 13 16:24:39 volumio volumio[924]: verbose: New Socket.io Connection to 192.168.1.171 from 192.168.1.110 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:146.0) Gecko/20100101 Firefox/146.0 Engine version: 3 Transport: polling Total Clients: 5 Dec 13 16:24:39 volumio sudo[15225]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 13 16:24:39 volumio sudo[15225]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 16:24:39 volumio sudo[15225]: pam_unix(sudo:session): session closed for user root Dec 13 16:24:39 volumio sudo[15227]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 13 16:24:39 volumio sudo[15227]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 13 16:24:39 volumio sudo[15227]: pam_unix(sudo:session): session closed for user root Dec 13 16:24:39 volumio volumio[924]: verbose: New Socket.io Connection to 192.168.1.171 from 192.168.1.110 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:146.0) Gecko/20100101 Firefox/146.0 Engine version: 3 Transport: polling Total Clients: 6 Dec 13 16:24:39 volumio volumio[924]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 13 16:24:39 volumio volumio[924]: info: CoreCommandRouter::volumioGetVisibleSources Dec 13 16:24:39 volumio volumio[924]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 13 16:24:39 volumio volumio[924]: info: CoreCommandRouter::volumioGetState Dec 13 16:24:39 volumio volumio[924]: info: CorePlayQueue::getTrack 5 Dec 13 16:24:39 volumio volumio[924]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 13 16:24:39 volumio volumio[924]: info: CoreCommandRouter::volumioGetQueue Dec 13 16:24:39 volumio volumio[924]: info: CoreStateMachine::getQueue Dec 13 16:24:39 volumio volumio[924]: info: CorePlayQueue::getQueue Dec 13 16:24:39 volumio volumio[924]: info: Listing playlists Dec 13 16:24:39 volumio volumio[924]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 13 16:24:39 volumio volumio[924]: info: Received Get System Info Dec 13 16:24:39 volumio volumio[924]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 13 16:24:39 volumio volumio[924]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 13 16:24:39 volumio volumio[924]: info: Discovery: Getting this device information Dec 13 16:24:39 volumio volumio[924]: info: CoreCommandRouter::volumioGetState Dec 13 16:24:39 volumio volumio[924]: info: CorePlayQueue::getTrack 5 Dec 13 16:24:39 volumio volumio[924]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 13 16:24:39 volumio volumio[924]: info: CoreCommandRouter::volumioGetState Dec 13 16:24:39 volumio volumio[924]: info: CorePlayQueue::getTrack 5 Dec 13 16:24:39 volumio volumio[924]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Dec 13 16:24:39 volumio volumio[924]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 13 16:24:41 volumio volumio[924]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Dec 13 16:24:41 volumio volumio[924]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 13 16:24:41 volumio volumio[924]: info: Received Get System Info Dec 13 16:24:41 volumio volumio[924]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 13 16:24:41 volumio volumio[924]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 13 16:24:41 volumio volumio[924]: info: Discovery: Getting this device information Dec 13 16:24:41 volumio volumio[924]: info: CoreCommandRouter::volumioGetState Dec 13 16:24:41 volumio volumio[924]: info: CorePlayQueue::getTrack 5 Dec 13 16:24:41 volumio volumio[924]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 13 16:24:41 volumio volumio[924]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 13 16:24:46 volumio volumio[924]: info: CoreCommandRouter::volumioGetState Dec 13 16:24:46 volumio volumio[924]: info: CorePlayQueue::getTrack 5 Dec 13 16:24:49 volumio volumio[924]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Dec 13 16:24:50 volumio volumio[924]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 13 16:24:50 volumio volumio[924]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Dec 13 16:24:50 volumio volumio[924]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Dec 13 16:24:50 volumio volumio[924]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Dec 13 16:24:50 volumio volumio[924]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableUIs Dec 13 16:24:50 volumio volumio[924]: info: Received Get System Version Dec 13 16:24:50 volumio volumio[924]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 13 16:24:56 volumio ntpd[807]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Dec 13 16:25:01 volumio go-librespot[15196]: time="2025-12-13T16:25:01Z" 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" Dec 13 16:25:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 13 16:25:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 13 16:25:01 volumio volumio[924]: (node:924) UnhandledPromiseRejectionWarning: Error: socket hang up Dec 13 16:25:01 volumio volumio[924]: at connResetException (internal/errors.js:607:14) Dec 13 16:25:01 volumio volumio[924]: at Socket.socketOnEnd (_http_client.js:493:23) Dec 13 16:25:01 volumio volumio[924]: at Socket.emit (events.js:327:22) Dec 13 16:25:01 volumio volumio[924]: at endReadableNT (internal/streams/readable.js:1327:12) Dec 13 16:25:01 volumio volumio[924]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Dec 13 16:25:01 volumio volumio[924]: (node:924) 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: 38) Dec 13 16:25:01 volumio volumio[924]: info: Connection to go-librespot Websocket closed Dec 13 16:25:02 volumio volumio[924]: info: CoreCommandRouter::volumioGetState Dec 13 16:25:02 volumio volumio[924]: info: CorePlayQueue::getTrack 5 Dec 13 16:25:03 volumio volumio[924]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 13 16:25:03 volumio volumio[924]: [t [Error]: A network error (such as timeout, interrupted connection or unreachable host) has occurred.] { Dec 13 16:25:03 volumio volumio[924]: code: 'auth/network-request-failed', Dec 13 16:25:03 volumio volumio[924]: a: null Dec 13 16:25:03 volumio volumio[924]: } Dec 13 16:25:03 volumio volumio[924]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 13 16:25:04 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 13 16:25:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. Dec 13 16:25:04 volumio systemd[1]: Stopped go-librespot Daemon. Dec 13 16:25:04 volumio systemd[1]: Started go-librespot Daemon. Dec 13 16:25:04 volumio go-librespot[15324]: go-librespot daemon starting... Dec 13 16:25:04 volumio go-librespot[15324]: time="2025-12-13T16:25:04Z" level=info msg="running go-librespot 0.4.0" Dec 13 16:25:04 volumio go-librespot[15324]: time="2025-12-13T16:25:04Z" level=debug msg="app state loaded" Dec 13 16:25:04 volumio go-librespot[15324]: time="2025-12-13T16:25:04Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 13 16:25:04 volumio sudo[15333]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-12-13 16:24 Dec 13 16:25:04 volumio sudo[15333]: 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="cc50ad4a2058d01de272214eb33827883bd2b7d8" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="502750e5d54ecf269d25125b622bfabc030fb553" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 12 Nov 2025 06:58:02 PM CET" VOLUMIO_VERSION="3.874" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="4ae6504ed6f22e44c01a6e93b16badbd"