-- Logs begin at Sat 2024-08-31 21:46:24 CEST, end at Sun 2024-09-01 02:24:21 CEST. -- Sep 01 02:23:05 mc go-librespot[3985]: time="2024-09-01T02:23:05+02:00" level=debug msg="new websocket client" Sep 01 02:23:05 mc volumio[1211]: info: Connection to go-librespot Websocket established Sep 01 02:23:08 mc volumio[1211]: info: Getting Spotify volume Sep 01 02:23:08 mc volumio[1211]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Sep 01 02:23:08 mc volumio[1211]: info: CoreCommandRouter::volumioGetState Sep 01 02:23:08 mc volumio[1211]: info: CorePlayQueue::getTrack 10 Sep 01 02:23:08 mc volumio[1211]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Sep 01 02:23:13 mc ntpd[1501]: receive: Unexpected origin timestamp 0xea7e318c.c246d22e does not match aorg 0xea7e325a.c24aea3f from server@193.2.78.2 xmt 0xea7e3271.377872f5 Sep 01 02:23:13 mc ntpd[1501]: receive: Unexpected origin timestamp 0xea7e318c.c249bc8d does not match aorg 0xea7e3254.c24279ba from server@84.255.235.43 xmt 0xea7e3271.743292d7 Sep 01 02:23:16 mc go-librespot[3985]: time="2024-09-01T02:23:16+02:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Sep 01 02:23:16 mc systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 02:23:16 mc systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 02:23:16 mc volumio[1211]: (node:1211) UnhandledPromiseRejectionWarning: Error: socket hang up Sep 01 02:23:16 mc volumio[1211]: at connResetException (internal/errors.js:639:14) Sep 01 02:23:16 mc volumio[1211]: at Socket.socketOnEnd (_http_client.js:499:23) Sep 01 02:23:16 mc volumio[1211]: at Socket.emit (events.js:412:35) Sep 01 02:23:16 mc volumio[1211]: at endReadableNT (internal/streams/readable.js:1333:12) Sep 01 02:23:16 mc volumio[1211]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Sep 01 02:23:16 mc volumio[1211]: (node:1211) 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: 508) Sep 01 02:23:16 mc volumio[1211]: info: Connection to go-librespot Websocket closed Sep 01 02:23:17 mc ntpd[1501]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Sep 01 02:23:19 mc volumio[1211]: info: Initializing connection to go-librespot Websocket Sep 01 02:23:19 mc volumio[1211]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 01 02:23:19 mc systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 01 02:23:19 mc systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2407. Sep 01 02:23:19 mc systemd[1]: Stopped go-librespot Daemon. Sep 01 02:23:19 mc systemd[1]: Started go-librespot Daemon. Sep 01 02:23:19 mc go-librespot[4102]: Librespot-go daemon starting... Sep 01 02:23:19 mc go-librespot[4102]: time="2024-09-01T02:23:19+02:00" level=info msg="generated new device id: 38f04f69399723fedb3005cea94d6b1b9e6a3fd6" Sep 01 02:23:19 mc go-librespot[4102]: time="2024-09-01T02:23:19+02:00" level=debug msg="stored credentials found for 31biwbusnbyl4g4dgq6koqhzkena" Sep 01 02:23:22 mc volumio[1211]: info: Initializing connection to go-librespot Websocket Sep 01 02:23:22 mc go-librespot[4102]: time="2024-09-01T02:23:22+02:00" level=debug msg="new websocket client" Sep 01 02:23:22 mc volumio[1211]: info: Connection to go-librespot Websocket established Sep 01 02:23:23 mc volumio[1211]: info: CoreCommandRouter::volumioRemoveQueueItem Sep 01 02:23:23 mc volumio[1211]: info: CoreStateMachine::removeQueueItem Sep 01 02:23:23 mc volumio[1211]: info: CorePlayQueue::removeQueueItem 16 Sep 01 02:23:23 mc volumio[1211]: info: CorePlayQueue::saveQueue Sep 01 02:23:23 mc volumio[1211]: info: CoreCommandRouter::volumioPushQueue Sep 01 02:23:25 mc volumio[1211]: info: Getting Spotify volume Sep 01 02:23:25 mc volumio[1211]: info: CoreCommandRouter::volumioRemoveQueueItem Sep 01 02:23:25 mc volumio[1211]: info: CoreStateMachine::removeQueueItem Sep 01 02:23:25 mc volumio[1211]: info: CorePlayQueue::removeQueueItem 17 Sep 01 02:23:25 mc volumio[1211]: info: CorePlayQueue::saveQueue Sep 01 02:23:25 mc volumio[1211]: info: CoreCommandRouter::volumioPushQueue Sep 01 02:23:26 mc volumio[1211]: info: CoreCommandRouter::volumioRemoveQueueItem Sep 01 02:23:26 mc volumio[1211]: info: CoreStateMachine::removeQueueItem Sep 01 02:23:26 mc volumio[1211]: info: CorePlayQueue::removeQueueItem 17 Sep 01 02:23:26 mc volumio[1211]: info: CorePlayQueue::saveQueue Sep 01 02:23:26 mc volumio[1211]: info: CoreCommandRouter::volumioPushQueue Sep 01 02:23:32 mc volumio[1211]: info: CoreCommandRouter::volumioRemoveQueueItem Sep 01 02:23:32 mc volumio[1211]: info: CoreStateMachine::removeQueueItem Sep 01 02:23:32 mc volumio[1211]: info: CorePlayQueue::removeQueueItem 17 Sep 01 02:23:32 mc volumio[1211]: info: CorePlayQueue::saveQueue Sep 01 02:23:32 mc volumio[1211]: info: CoreCommandRouter::volumioPushQueue Sep 01 02:23:33 mc volumio[1211]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Sep 01 02:23:33 mc volumio[1211]: info: CoreCommandRouter::volumioGetState Sep 01 02:23:33 mc volumio[1211]: info: CorePlayQueue::getTrack 10 Sep 01 02:23:33 mc volumio[1211]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Sep 01 02:23:33 mc volumio[1211]: info: CoreCommandRouter::volumioRemoveQueueItem Sep 01 02:23:33 mc volumio[1211]: info: CoreStateMachine::removeQueueItem Sep 01 02:23:33 mc volumio[1211]: info: CorePlayQueue::removeQueueItem 17 Sep 01 02:23:33 mc volumio[1211]: info: CorePlayQueue::saveQueue Sep 01 02:23:33 mc volumio[1211]: info: CoreCommandRouter::volumioPushQueue Sep 01 02:23:40 mc volumio[1211]: info: CoreCommandRouter::volumioRemoveQueueItem Sep 01 02:23:40 mc volumio[1211]: info: CoreStateMachine::removeQueueItem Sep 01 02:23:40 mc volumio[1211]: info: CorePlayQueue::removeQueueItem 19 Sep 01 02:23:40 mc volumio[1211]: info: CorePlayQueue::saveQueue Sep 01 02:23:40 mc volumio[1211]: info: CoreCommandRouter::volumioPushQueue Sep 01 02:23:42 mc volumio[1211]: info: CoreCommandRouter::volumioRemoveQueueItem Sep 01 02:23:42 mc volumio[1211]: info: CoreStateMachine::removeQueueItem Sep 01 02:23:42 mc volumio[1211]: info: CorePlayQueue::removeQueueItem 19 Sep 01 02:23:42 mc volumio[1211]: info: CorePlayQueue::saveQueue Sep 01 02:23:42 mc volumio[1211]: info: CoreCommandRouter::volumioPushQueue Sep 01 02:23:47 mc go-librespot[4102]: time="2024-09-01T02:23:47+02:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Sep 01 02:23:47 mc systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 02:23:47 mc systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 02:23:47 mc volumio[1211]: (node:1211) UnhandledPromiseRejectionWarning: Error: socket hang up Sep 01 02:23:47 mc volumio[1211]: at connResetException (internal/errors.js:639:14) Sep 01 02:23:47 mc volumio[1211]: at Socket.socketOnEnd (_http_client.js:499:23) Sep 01 02:23:47 mc volumio[1211]: at Socket.emit (events.js:412:35) Sep 01 02:23:47 mc volumio[1211]: at endReadableNT (internal/streams/readable.js:1333:12) Sep 01 02:23:47 mc volumio[1211]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Sep 01 02:23:47 mc volumio[1211]: (node:1211) 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: 509) Sep 01 02:23:47 mc volumio[1211]: info: Connection to go-librespot Websocket closed Sep 01 02:23:50 mc volumio[1211]: info: Initializing connection to go-librespot Websocket Sep 01 02:23:50 mc systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 01 02:23:50 mc systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2408. Sep 01 02:23:50 mc systemd[1]: Stopped go-librespot Daemon. Sep 01 02:23:50 mc systemd[1]: Started go-librespot Daemon. Sep 01 02:23:50 mc go-librespot[4174]: Librespot-go daemon starting... Sep 01 02:23:50 mc go-librespot[4174]: time="2024-09-01T02:23:50+02:00" level=info msg="generated new device id: a7e8a4701a4ef4df041f703dc47a92a5f9f748a8" Sep 01 02:23:50 mc go-librespot[4174]: time="2024-09-01T02:23:50+02:00" level=debug msg="stored credentials found for 31biwbusnbyl4g4dgq6koqhzkena" Sep 01 02:23:51 mc ntpd[1501]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Sep 01 02:23:53 mc volumio[1211]: info: CoreCommandRouter::volumioGetState Sep 01 02:23:53 mc volumio[1211]: info: CorePlayQueue::getTrack 10 Sep 01 02:24:01 mc volumio[1211]: Searching plugin music_service/mpd Sep 01 02:24:01 mc volumio[1211]: info: CoreCommandRouter::executeOnPlugin: mpd , search Sep 01 02:24:01 mc volumio[1211]: info: All search sources collected, pushing search results Sep 01 02:24:02 mc volumio[1211]: Searching plugin music_service/mpd Sep 01 02:24:02 mc volumio[1211]: info: CoreCommandRouter::executeOnPlugin: mpd , search Sep 01 02:24:02 mc volumio[1211]: info: All search sources collected, pushing search results Sep 01 02:24:05 mc go-librespot[4174]: time="2024-09-01T02:24:05+02:00" level=debug msg="new websocket client" Sep 01 02:24:05 mc volumio[1211]: info: Connection to go-librespot Websocket established Sep 01 02:24:07 mc volumio[1211]: Searching plugin music_service/mpd Sep 01 02:24:07 mc volumio[1211]: info: CoreCommandRouter::executeOnPlugin: mpd , search Sep 01 02:24:07 mc volumio[1211]: info: All search sources collected, pushing search results Sep 01 02:24:08 mc volumio[1211]: info: Getting Spotify volume Sep 01 02:24:08 mc volumio[1211]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Sep 01 02:24:08 mc volumio[1211]: info: CoreCommandRouter::volumioGetState Sep 01 02:24:08 mc volumio[1211]: info: CorePlayQueue::getTrack 10 Sep 01 02:24:08 mc volumio[1211]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Sep 01 02:24:18 mc go-librespot[4174]: time="2024-09-01T02:24:18+02:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Sep 01 02:24:18 mc systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 01 02:24:18 mc systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 01 02:24:18 mc volumio[1211]: (node:1211) UnhandledPromiseRejectionWarning: Error: socket hang up Sep 01 02:24:18 mc volumio[1211]: at connResetException (internal/errors.js:639:14) Sep 01 02:24:18 mc volumio[1211]: at Socket.socketOnEnd (_http_client.js:499:23) Sep 01 02:24:18 mc volumio[1211]: at Socket.emit (events.js:412:35) Sep 01 02:24:18 mc volumio[1211]: at endReadableNT (internal/streams/readable.js:1333:12) Sep 01 02:24:18 mc volumio[1211]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Sep 01 02:24:18 mc volumio[1211]: (node:1211) 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: 511) Sep 01 02:24:18 mc volumio[1211]: info: Connection to go-librespot Websocket closed Sep 01 02:24:19 mc ntpd[1501]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Sep 01 02:24:21 mc volumio[1211]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 01 02:24:21 mc volumio[1211]: Error: read ECONNRESET Sep 01 02:24:21 mc volumio[1211]: at TLSWrap.onStreamRead (internal/stream_base_commons.js:209:20) { Sep 01 02:24:21 mc volumio[1211]: errno: -104, Sep 01 02:24:21 mc volumio[1211]: code: 'ECONNRESET', Sep 01 02:24:21 mc volumio[1211]: syscall: 'read' Sep 01 02:24:21 mc volumio[1211]: } Sep 01 02:24:21 mc volumio[1211]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 01 02:24:21 mc sudo[4300]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-09-01 02:23 Sep 01 02:24:21 mc sudo[4300]: 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="5fd3886148e72a9cecd88a772d1f6079fb64d11a" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8bb23b009e91ae4c7ecd678f193e7d3b281fca0c" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 22 Jul 2024 07:48:50 PM CEST" VOLUMIO_VERSION="3.742" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="1049be5fd382035818795b7f5c38e10d"