-- 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"