-- Logs begin at Thu 2024-07-04 03:14:37 CDT, end at Tue 2024-07-09 23:29:36 CDT. -- Jul 09 23:28:02 lachlans-stereo volumio[12082]: info: Initializing connection to go-librespot Websocket Jul 09 23:28:02 lachlans-stereo go-librespot[1548]: time="2024-07-09T23:28:02-05:00" level=debug msg="new websocket client" Jul 09 23:28:02 lachlans-stereo volumio[12082]: info: Connection to go-librespot Websocket established Jul 09 23:28:05 lachlans-stereo volumio[12082]: info: Getting Spotify volume Jul 09 23:28:05 lachlans-stereo volumio[12082]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 5 Jul 09 23:28:05 lachlans-stereo volumio[12082]: info: CoreCommandRouter::volumioGetState Jul 09 23:28:05 lachlans-stereo volumio[12082]: info: CorePlayQueue::getTrack 0 Jul 09 23:28:05 lachlans-stereo volumio[12082]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jul 09 23:28:05 lachlans-stereo volumio[12082]: SPOTIFY: SPOTIFY VOLUME 100 Jul 09 23:28:05 lachlans-stereo volumio[12082]: SPOTIFY: VOLUMIO VOLUME 100 Jul 09 23:28:05 lachlans-stereo volumio[12082]: SPOTIFY: DELTA VOLUME ENOUGH: false Jul 09 23:28:27 lachlans-stereo go-librespot[1548]: time="2024-07-09T23:28:27-05: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" Jul 09 23:28:27 lachlans-stereo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 09 23:28:27 lachlans-stereo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 09 23:28:27 lachlans-stereo volumio[12082]: (node:12082) UnhandledPromiseRejectionWarning: Error: socket hang up Jul 09 23:28:27 lachlans-stereo volumio[12082]: at connResetException (internal/errors.js:607:14) Jul 09 23:28:27 lachlans-stereo volumio[12082]: at Socket.socketOnEnd (_http_client.js:493:23) Jul 09 23:28:27 lachlans-stereo volumio[12082]: at Socket.emit (events.js:327:22) Jul 09 23:28:27 lachlans-stereo volumio[12082]: at endReadableNT (internal/streams/readable.js:1327:12) Jul 09 23:28:27 lachlans-stereo volumio[12082]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Jul 09 23:28:27 lachlans-stereo volumio[12082]: (node:12082) 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: 712) Jul 09 23:28:27 lachlans-stereo volumio[12082]: info: Connection to go-librespot Websocket closed Jul 09 23:28:27 lachlans-stereo nmbd[604]: [2024/07/09 23:28:27.456362, 0] ../source3/nmbd/nmbd_nameregister.c:73(register_name_response) Jul 09 23:28:27 lachlans-stereo nmbd[604]: register_name_response: Answer name <00> differs from question name <00>. Jul 09 23:28:27 lachlans-stereo nmbd[604]: [2024/07/09 23:28:27.456757, 0] ../source3/nmbd/nmbd_nameregister.c:73(register_name_response) Jul 09 23:28:27 lachlans-stereo nmbd[604]: register_name_response: Answer name <03> differs from question name <03>. Jul 09 23:28:27 lachlans-stereo nmbd[604]: [2024/07/09 23:28:27.457027, 0] ../source3/nmbd/nmbd_nameregister.c:73(register_name_response) Jul 09 23:28:27 lachlans-stereo nmbd[604]: register_name_response: Answer name <20> differs from question name <20>. Jul 09 23:28:30 lachlans-stereo volumio[12082]: info: Initializing connection to go-librespot Websocket Jul 09 23:28:30 lachlans-stereo volumio[12082]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 09 23:28:30 lachlans-stereo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 09 23:28:30 lachlans-stereo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 845. Jul 09 23:28:30 lachlans-stereo systemd[1]: Stopped go-librespot Daemon. Jul 09 23:28:30 lachlans-stereo systemd[1]: Started go-librespot Daemon. Jul 09 23:28:30 lachlans-stereo go-librespot[1558]: Librespot-go daemon starting... Jul 09 23:28:30 lachlans-stereo go-librespot[1558]: time="2024-07-09T23:28:30-05:00" level=info msg="generated new device id: 73973c240b60b92be439fadbc5923137a778df7b" Jul 09 23:28:30 lachlans-stereo go-librespot[1558]: time="2024-07-09T23:28:30-05:00" level=debug msg="stored credentials found for 31ya4xm4cgs5pmzptafjen6pmcxi" Jul 09 23:28:33 lachlans-stereo volumio[12082]: info: Initializing connection to go-librespot Websocket Jul 09 23:28:33 lachlans-stereo go-librespot[1558]: time="2024-07-09T23:28:33-05:00" level=debug msg="new websocket client" Jul 09 23:28:33 lachlans-stereo volumio[12082]: info: Connection to go-librespot Websocket established Jul 09 23:28:34 lachlans-stereo volumiologrotate[483]: ls: cannot access '/var/log/samba/log.wb-LACHLAN’S': No such file or directory Jul 09 23:28:34 lachlans-stereo volumiologrotate[483]: ls: cannot access 'STEREO': No such file or directory Jul 09 23:28:36 lachlans-stereo volumio[12082]: info: Getting Spotify volume Jul 09 23:28:36 lachlans-stereo volumio[12082]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 5 Jul 09 23:28:36 lachlans-stereo volumio[12082]: info: CoreCommandRouter::volumioGetState Jul 09 23:28:36 lachlans-stereo volumio[12082]: info: CorePlayQueue::getTrack 0 Jul 09 23:28:36 lachlans-stereo volumio[12082]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jul 09 23:28:36 lachlans-stereo volumio[12082]: SPOTIFY: SPOTIFY VOLUME 100 Jul 09 23:28:36 lachlans-stereo volumio[12082]: SPOTIFY: VOLUMIO VOLUME 100 Jul 09 23:28:36 lachlans-stereo volumio[12082]: SPOTIFY: DELTA VOLUME ENOUGH: false Jul 09 23:28:47 lachlans-stereo go-librespot[1558]: time="2024-07-09T23:28:47-05: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\": net/http: TLS handshake timeout" Jul 09 23:28:47 lachlans-stereo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 09 23:28:47 lachlans-stereo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 09 23:28:47 lachlans-stereo volumio[12082]: (node:12082) UnhandledPromiseRejectionWarning: Error: socket hang up Jul 09 23:28:47 lachlans-stereo volumio[12082]: at connResetException (internal/errors.js:607:14) Jul 09 23:28:47 lachlans-stereo volumio[12082]: at Socket.socketOnEnd (_http_client.js:493:23) Jul 09 23:28:47 lachlans-stereo volumio[12082]: at Socket.emit (events.js:327:22) Jul 09 23:28:47 lachlans-stereo volumio[12082]: at endReadableNT (internal/streams/readable.js:1327:12) Jul 09 23:28:47 lachlans-stereo volumio[12082]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Jul 09 23:28:47 lachlans-stereo volumio[12082]: (node:12082) 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: 713) Jul 09 23:28:47 lachlans-stereo volumio[12082]: info: Connection to go-librespot Websocket closed Jul 09 23:28:50 lachlans-stereo volumio[12082]: info: Initializing connection to go-librespot Websocket Jul 09 23:28:50 lachlans-stereo volumio[12082]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 09 23:28:51 lachlans-stereo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 09 23:28:51 lachlans-stereo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 846. Jul 09 23:28:51 lachlans-stereo systemd[1]: Stopped go-librespot Daemon. Jul 09 23:28:51 lachlans-stereo systemd[1]: Started go-librespot Daemon. Jul 09 23:28:51 lachlans-stereo go-librespot[1606]: Librespot-go daemon starting... Jul 09 23:28:51 lachlans-stereo go-librespot[1606]: time="2024-07-09T23:28:51-05:00" level=info msg="generated new device id: 7d4bf69554e610e7cdf730df3d4f5b47f8397004" Jul 09 23:28:51 lachlans-stereo go-librespot[1606]: time="2024-07-09T23:28:51-05:00" level=debug msg="stored credentials found for 31ya4xm4cgs5pmzptafjen6pmcxi" Jul 09 23:28:53 lachlans-stereo volumio[12082]: info: Initializing connection to go-librespot Websocket Jul 09 23:28:53 lachlans-stereo go-librespot[1606]: time="2024-07-09T23:28:53-05:00" level=debug msg="new websocket client" Jul 09 23:28:53 lachlans-stereo volumio[12082]: info: Connection to go-librespot Websocket established Jul 09 23:28:56 lachlans-stereo volumio[12082]: info: Getting Spotify volume Jul 09 23:28:56 lachlans-stereo volumio[12082]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 5 Jul 09 23:28:56 lachlans-stereo volumio[12082]: info: CoreCommandRouter::volumioGetState Jul 09 23:28:56 lachlans-stereo volumio[12082]: info: CorePlayQueue::getTrack 0 Jul 09 23:28:56 lachlans-stereo volumio[12082]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jul 09 23:28:56 lachlans-stereo volumio[12082]: SPOTIFY: SPOTIFY VOLUME 100 Jul 09 23:28:56 lachlans-stereo volumio[12082]: SPOTIFY: VOLUMIO VOLUME 100 Jul 09 23:28:56 lachlans-stereo volumio[12082]: SPOTIFY: DELTA VOLUME ENOUGH: false Jul 09 23:29:02 lachlans-stereo go-librespot[1606]: time="2024-07-09T23:29:02-05: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\": net/http: TLS handshake timeout" Jul 09 23:29:02 lachlans-stereo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 09 23:29:02 lachlans-stereo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 09 23:29:02 lachlans-stereo volumio[12082]: (node:12082) UnhandledPromiseRejectionWarning: Error: socket hang up Jul 09 23:29:02 lachlans-stereo volumio[12082]: at connResetException (internal/errors.js:607:14) Jul 09 23:29:02 lachlans-stereo volumio[12082]: at Socket.socketOnEnd (_http_client.js:493:23) Jul 09 23:29:02 lachlans-stereo volumio[12082]: at Socket.emit (events.js:327:22) Jul 09 23:29:02 lachlans-stereo volumio[12082]: at endReadableNT (internal/streams/readable.js:1327:12) Jul 09 23:29:02 lachlans-stereo volumio[12082]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Jul 09 23:29:02 lachlans-stereo volumio[12082]: (node:12082) 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: 714) Jul 09 23:29:02 lachlans-stereo volumio[12082]: info: Connection to go-librespot Websocket closed Jul 09 23:29:05 lachlans-stereo volumio[12082]: info: Initializing connection to go-librespot Websocket Jul 09 23:29:05 lachlans-stereo volumio[12082]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 09 23:29:05 lachlans-stereo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 09 23:29:05 lachlans-stereo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 847. Jul 09 23:29:05 lachlans-stereo systemd[1]: Stopped go-librespot Daemon. Jul 09 23:29:05 lachlans-stereo systemd[1]: Started go-librespot Daemon. Jul 09 23:29:05 lachlans-stereo go-librespot[1614]: Librespot-go daemon starting... Jul 09 23:29:05 lachlans-stereo go-librespot[1614]: time="2024-07-09T23:29:05-05:00" level=info msg="generated new device id: 4ea40baa2fbd6f860e674507f3aa2def28e7a2a9" Jul 09 23:29:05 lachlans-stereo go-librespot[1614]: time="2024-07-09T23:29:05-05:00" level=debug msg="stored credentials found for 31ya4xm4cgs5pmzptafjen6pmcxi" Jul 09 23:29:08 lachlans-stereo volumio[12082]: info: Initializing connection to go-librespot Websocket Jul 09 23:29:11 lachlans-stereo go-librespot[1614]: time="2024-07-09T23:29:11-05:00" level=debug msg="new websocket client" Jul 09 23:29:11 lachlans-stereo volumio[12082]: info: Connection to go-librespot Websocket established Jul 09 23:29:14 lachlans-stereo volumio[12082]: info: Getting Spotify volume Jul 09 23:29:14 lachlans-stereo volumio[12082]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 5 Jul 09 23:29:14 lachlans-stereo volumio[12082]: info: CoreCommandRouter::volumioGetState Jul 09 23:29:14 lachlans-stereo volumio[12082]: info: CorePlayQueue::getTrack 0 Jul 09 23:29:14 lachlans-stereo volumio[12082]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jul 09 23:29:14 lachlans-stereo volumio[12082]: SPOTIFY: SPOTIFY VOLUME 100 Jul 09 23:29:14 lachlans-stereo volumio[12082]: SPOTIFY: VOLUMIO VOLUME 100 Jul 09 23:29:14 lachlans-stereo volumio[12082]: SPOTIFY: DELTA VOLUME ENOUGH: false Jul 09 23:29:18 lachlans-stereo go-librespot[1614]: time="2024-07-09T23:29:18-05: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\": net/http: TLS handshake timeout" Jul 09 23:29:18 lachlans-stereo volumio[12082]: (node:12082) UnhandledPromiseRejectionWarning: Error: socket hang up Jul 09 23:29:18 lachlans-stereo volumio[12082]: at connResetException (internal/errors.js:607:14) Jul 09 23:29:18 lachlans-stereo volumio[12082]: at Socket.socketOnEnd (_http_client.js:493:23) Jul 09 23:29:18 lachlans-stereo volumio[12082]: at Socket.emit (events.js:327:22) Jul 09 23:29:18 lachlans-stereo volumio[12082]: at endReadableNT (internal/streams/readable.js:1327:12) Jul 09 23:29:18 lachlans-stereo volumio[12082]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Jul 09 23:29:18 lachlans-stereo volumio[12082]: (node:12082) 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: 715) Jul 09 23:29:18 lachlans-stereo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 09 23:29:18 lachlans-stereo volumio[12082]: info: Connection to go-librespot Websocket closed Jul 09 23:29:18 lachlans-stereo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 09 23:29:21 lachlans-stereo volumio[12082]: info: Initializing connection to go-librespot Websocket Jul 09 23:29:21 lachlans-stereo volumio[12082]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 09 23:29:21 lachlans-stereo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 09 23:29:21 lachlans-stereo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 848. Jul 09 23:29:21 lachlans-stereo systemd[1]: Stopped go-librespot Daemon. Jul 09 23:29:21 lachlans-stereo systemd[1]: Started go-librespot Daemon. Jul 09 23:29:21 lachlans-stereo go-librespot[1624]: Librespot-go daemon starting... Jul 09 23:29:21 lachlans-stereo go-librespot[1624]: time="2024-07-09T23:29:21-05:00" level=info msg="generated new device id: de559ffa39f6efed1dffabcc6f6f2342d13f6aa3" Jul 09 23:29:21 lachlans-stereo go-librespot[1624]: time="2024-07-09T23:29:21-05:00" level=debug msg="stored credentials found for 31ya4xm4cgs5pmzptafjen6pmcxi" Jul 09 23:29:24 lachlans-stereo volumio[12082]: info: Initializing connection to go-librespot Websocket Jul 09 23:29:24 lachlans-stereo go-librespot[1624]: time="2024-07-09T23:29:24-05:00" level=debug msg="new websocket client" Jul 09 23:29:24 lachlans-stereo volumio[12082]: info: Connection to go-librespot Websocket established Jul 09 23:29:27 lachlans-stereo volumio[12082]: info: Getting Spotify volume Jul 09 23:29:27 lachlans-stereo volumio[12082]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 5 Jul 09 23:29:27 lachlans-stereo volumio[12082]: info: CoreCommandRouter::volumioGetState Jul 09 23:29:27 lachlans-stereo volumio[12082]: info: CorePlayQueue::getTrack 0 Jul 09 23:29:27 lachlans-stereo volumio[12082]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jul 09 23:29:27 lachlans-stereo volumio[12082]: SPOTIFY: SPOTIFY VOLUME 100 Jul 09 23:29:27 lachlans-stereo volumio[12082]: SPOTIFY: VOLUMIO VOLUME 100 Jul 09 23:29:27 lachlans-stereo volumio[12082]: SPOTIFY: DELTA VOLUME ENOUGH: false Jul 09 23:29:31 lachlans-stereo volumio[12082]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 09 23:29:31 lachlans-stereo volumio[12082]: [t [Error]: A network error (such as timeout, interrupted connection or unreachable host) has occurred.] { Jul 09 23:29:31 lachlans-stereo volumio[12082]: code: 'auth/network-request-failed', Jul 09 23:29:31 lachlans-stereo volumio[12082]: a: null Jul 09 23:29:31 lachlans-stereo volumio[12082]: } Jul 09 23:29:31 lachlans-stereo volumio[12082]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 09 23:29:34 lachlans-stereo volumiologrotate[483]: ls: cannot access '/var/log/samba/log.wb-LACHLAN’S': No such file or directory Jul 09 23:29:34 lachlans-stereo volumiologrotate[483]: ls: cannot access 'STEREO': No such file or directory Jul 09 23:29:36 lachlans-stereo sudo[1641]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-07-09 23:28 Jul 09 23:29:36 lachlans-stereo sudo[1641]: 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="7f9f1bf001add7a8b19a4516e3c74ef598b2730d" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="512433c3e91cdaed7ecd2808b21adeffc2137d7f" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 21 Feb 2024 09:37:22 PM CET" VOLUMIO_VERSION="3.631" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fdd9dd1169c06c1ad0a30ddd24c91b6b"