-- Logs begin at Sun 2024-07-21 20:45:49 CEST, end at Mon 2024-07-22 02:34:29 CEST. --
Jul 22 02:33:01 rpi-volumio-te volumio[846]: info: Initializing connection to go-librespot Websocket
Jul 22 02:33:01 rpi-volumio-te volumio[846]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 22 02:33:01 rpi-volumio-te systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 22 02:33:01 rpi-volumio-te systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 152928.
Jul 22 02:33:01 rpi-volumio-te systemd[1]: Stopped go-librespot Daemon.
Jul 22 02:33:01 rpi-volumio-te systemd[1]: Started go-librespot Daemon.
Jul 22 02:33:01 rpi-volumio-te go-librespot[7445]: Librespot-go daemon starting...
Jul 22 02:33:01 rpi-volumio-te go-librespot[7445]: time="2024-07-22T02:33:01+02:00" level=info msg="generated new device id: a9be62af9fb126a4c3487885a4a77a740e5e7619"
Jul 22 02:33:01 rpi-volumio-te go-librespot[7445]: time="2024-07-22T02:33:01+02:00" level=debug msg="stored credentials found for tenex24"
Jul 22 02:33:04 rpi-volumio-te volumio[846]: info: Initializing connection to go-librespot Websocket
Jul 22 02:33:04 rpi-volumio-te go-librespot[7445]: time="2024-07-22T02:33:04+02:00" level=debug msg="new websocket client"
Jul 22 02:33:04 rpi-volumio-te volumio[846]: info: Connection to go-librespot Websocket established
Jul 22 02:33:07 rpi-volumio-te volumio[846]: info: Getting Spotify volume
Jul 22 02:33:07 rpi-volumio-te volumio[846]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 5
Jul 22 02:33:07 rpi-volumio-te volumio[846]: info: CoreCommandRouter::volumioGetState
Jul 22 02:33:07 rpi-volumio-te volumio[846]: info: CorePlayQueue::getTrack 0
Jul 22 02:33:07 rpi-volumio-te volumio[846]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25
Jul 22 02:33:11 rpi-volumio-te go-librespot[7445]: time="2024-07-22T02:33:11+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\": net/http: TLS handshake timeout"
Jul 22 02:33:11 rpi-volumio-te systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 22 02:33:11 rpi-volumio-te systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 22 02:33:11 rpi-volumio-te volumio[846]: (node:846) UnhandledPromiseRejectionWarning: Error: socket hang up
Jul 22 02:33:11 rpi-volumio-te volumio[846]: at connResetException (internal/errors.js:607:14)
Jul 22 02:33:11 rpi-volumio-te volumio[846]: at Socket.socketOnEnd (_http_client.js:493:23)
Jul 22 02:33:11 rpi-volumio-te volumio[846]: at Socket.emit (events.js:327:22)
Jul 22 02:33:11 rpi-volumio-te volumio[846]: at endReadableNT (internal/streams/readable.js:1327:12)
Jul 22 02:33:11 rpi-volumio-te volumio[846]: at processTicksAndRejections (internal/process/task_queues.js:80:21)
Jul 22 02:33:11 rpi-volumio-te volumio[846]: (node:846) 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: 1238)
Jul 22 02:33:11 rpi-volumio-te volumio[846]: info: Connection to go-librespot Websocket closed
Jul 22 02:33:14 rpi-volumio-te volumio[846]: info: Initializing connection to go-librespot Websocket
Jul 22 02:33:14 rpi-volumio-te volumio[846]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 22 02:33:15 rpi-volumio-te systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 22 02:33:15 rpi-volumio-te systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 152929.
Jul 22 02:33:15 rpi-volumio-te systemd[1]: Stopped go-librespot Daemon.
Jul 22 02:33:15 rpi-volumio-te systemd[1]: Started go-librespot Daemon.
Jul 22 02:33:15 rpi-volumio-te go-librespot[7494]: Librespot-go daemon starting...
Jul 22 02:33:15 rpi-volumio-te go-librespot[7494]: time="2024-07-22T02:33:15+02:00" level=info msg="generated new device id: 06a5132f78d7ec8648b1ab51bc4596ffdc60e444"
Jul 22 02:33:15 rpi-volumio-te go-librespot[7494]: time="2024-07-22T02:33:15+02:00" level=debug msg="stored credentials found for tenex24"
Jul 22 02:33:17 rpi-volumio-te volumio[846]: info: Initializing connection to go-librespot Websocket
Jul 22 02:33:17 rpi-volumio-te go-librespot[7494]: time="2024-07-22T02:33:17+02:00" level=debug msg="new websocket client"
Jul 22 02:33:17 rpi-volumio-te volumio[846]: info: Connection to go-librespot Websocket established
Jul 22 02:33:20 rpi-volumio-te volumio[846]: info: Getting Spotify volume
Jul 22 02:33:20 rpi-volumio-te volumio[846]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 5
Jul 22 02:33:21 rpi-volumio-te volumio[846]: info: CoreCommandRouter::volumioGetState
Jul 22 02:33:21 rpi-volumio-te volumio[846]: info: CorePlayQueue::getTrack 0
Jul 22 02:33:21 rpi-volumio-te volumio[846]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25
Jul 22 02:33:28 rpi-volumio-te go-librespot[7494]: time="2024-07-22T02:33:28+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\": net/http: TLS handshake timeout"
Jul 22 02:33:28 rpi-volumio-te systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 22 02:33:28 rpi-volumio-te systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 22 02:33:28 rpi-volumio-te volumio[846]: (node:846) UnhandledPromiseRejectionWarning: Error: socket hang up
Jul 22 02:33:28 rpi-volumio-te volumio[846]: at connResetException (internal/errors.js:607:14)
Jul 22 02:33:28 rpi-volumio-te volumio[846]: at Socket.socketOnEnd (_http_client.js:493:23)
Jul 22 02:33:28 rpi-volumio-te volumio[846]: at Socket.emit (events.js:327:22)
Jul 22 02:33:28 rpi-volumio-te volumio[846]: at endReadableNT (internal/streams/readable.js:1327:12)
Jul 22 02:33:28 rpi-volumio-te volumio[846]: at processTicksAndRejections (internal/process/task_queues.js:80:21)
Jul 22 02:33:28 rpi-volumio-te volumio[846]: (node:846) 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: 1240)
Jul 22 02:33:28 rpi-volumio-te volumio[846]: info: Connection to go-librespot Websocket closed
Jul 22 02:33:31 rpi-volumio-te volumio[846]: info: Initializing connection to go-librespot Websocket
Jul 22 02:33:31 rpi-volumio-te volumio[846]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 22 02:33:31 rpi-volumio-te systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 22 02:33:31 rpi-volumio-te systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 152930.
Jul 22 02:33:31 rpi-volumio-te systemd[1]: Stopped go-librespot Daemon.
Jul 22 02:33:31 rpi-volumio-te systemd[1]: Started go-librespot Daemon.
Jul 22 02:33:31 rpi-volumio-te go-librespot[7501]: Librespot-go daemon starting...
Jul 22 02:33:31 rpi-volumio-te go-librespot[7501]: time="2024-07-22T02:33:31+02:00" level=info msg="generated new device id: 73b28d7e62004d57862c982dc085ce95041fb419"
Jul 22 02:33:31 rpi-volumio-te go-librespot[7501]: time="2024-07-22T02:33:31+02:00" level=debug msg="stored credentials found for tenex24"
Jul 22 02:33:34 rpi-volumio-te volumio[846]: info: Initializing connection to go-librespot Websocket
Jul 22 02:33:34 rpi-volumio-te go-librespot[7501]: time="2024-07-22T02:33:34+02:00" level=debug msg="new websocket client"
Jul 22 02:33:34 rpi-volumio-te volumio[846]: info: Connection to go-librespot Websocket established
Jul 22 02:33:37 rpi-volumio-te volumio[846]: info: Getting Spotify volume
Jul 22 02:33:37 rpi-volumio-te volumio[846]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 5
Jul 22 02:33:37 rpi-volumio-te volumio[846]: info: CoreCommandRouter::volumioGetState
Jul 22 02:33:37 rpi-volumio-te volumio[846]: info: CorePlayQueue::getTrack 0
Jul 22 02:33:37 rpi-volumio-te volumio[846]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25
Jul 22 02:33:41 rpi-volumio-te go-librespot[7501]: time="2024-07-22T02:33:41+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\": unexpected EOF"
Jul 22 02:33:41 rpi-volumio-te systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 22 02:33:41 rpi-volumio-te systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 22 02:33:41 rpi-volumio-te volumio[846]: (node:846) UnhandledPromiseRejectionWarning: Error: socket hang up
Jul 22 02:33:41 rpi-volumio-te volumio[846]: at connResetException (internal/errors.js:607:14)
Jul 22 02:33:41 rpi-volumio-te volumio[846]: at Socket.socketOnEnd (_http_client.js:493:23)
Jul 22 02:33:41 rpi-volumio-te volumio[846]: at Socket.emit (events.js:327:22)
Jul 22 02:33:41 rpi-volumio-te volumio[846]: at endReadableNT (internal/streams/readable.js:1327:12)
Jul 22 02:33:41 rpi-volumio-te volumio[846]: at processTicksAndRejections (internal/process/task_queues.js:80:21)
Jul 22 02:33:41 rpi-volumio-te volumio[846]: (node:846) 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: 1241)
Jul 22 02:33:41 rpi-volumio-te volumio[846]: info: Connection to go-librespot Websocket closed
Jul 22 02:33:44 rpi-volumio-te volumio[846]: info: Initializing connection to go-librespot Websocket
Jul 22 02:33:44 rpi-volumio-te systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 22 02:33:44 rpi-volumio-te systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 152931.
Jul 22 02:33:44 rpi-volumio-te volumio[846]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 22 02:33:44 rpi-volumio-te systemd[1]: Stopped go-librespot Daemon.
Jul 22 02:33:44 rpi-volumio-te systemd[1]: Started go-librespot Daemon.
Jul 22 02:33:44 rpi-volumio-te go-librespot[7510]: Librespot-go daemon starting...
Jul 22 02:33:44 rpi-volumio-te go-librespot[7510]: time="2024-07-22T02:33:44+02:00" level=info msg="generated new device id: 38a88578b83207bcded3f70484fe86b6a0759e06"
Jul 22 02:33:44 rpi-volumio-te go-librespot[7510]: time="2024-07-22T02:33:44+02:00" level=debug msg="stored credentials found for tenex24"
Jul 22 02:33:45 rpi-volumio-te volumio[846]: info: Getting Push Notification urls
Jul 22 02:33:47 rpi-volumio-te volumio[846]: info: Initializing connection to go-librespot Websocket
Jul 22 02:33:47 rpi-volumio-te go-librespot[7510]: time="2024-07-22T02:33:47+02:00" level=debug msg="new websocket client"
Jul 22 02:33:47 rpi-volumio-te volumio[846]: info: Connection to go-librespot Websocket established
Jul 22 02:33:50 rpi-volumio-te volumio[846]: info: Getting Spotify volume
Jul 22 02:33:50 rpi-volumio-te volumio[846]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 5
Jul 22 02:33:50 rpi-volumio-te volumio[846]: info: CoreCommandRouter::volumioGetState
Jul 22 02:33:50 rpi-volumio-te volumio[846]: info: CorePlayQueue::getTrack 0
Jul 22 02:33:50 rpi-volumio-te volumio[846]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25
Jul 22 02:33:51 rpi-volumio-te go-librespot[7510]: time="2024-07-22T02:33:51+02:00" level=debug msg="obtained new client token: AAAkZoJO4AhWjP+kuNXg6J9iRVDOjOPBZ+YN4Dlcl4bQ72CGdF+sKVQgHz4tQDpjyYBFk+MkU1zMj1s3p7zmhbdGXY764PlZcQkn6X4UQJCHR3IpPQMAqB60rNkflm3oygImL8hB1LNampThUs1DlfPA1gAPQuZIWKvxgNm40hN6uLJnyWqwEIM4ds/V6nDCvOsqmse3IpPIzLKA5ziyhB9AWzhNq8gIQSL3pf3qBMP+yqdQk/AvpOvEwA4="
Jul 22 02:33:53 rpi-volumio-te go-librespot[7510]: time="2024-07-22T02:33:53+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Jul 22 02:33:53 rpi-volumio-te go-librespot[7510]: time="2024-07-22T02:33:53+02:00" level=debug msg="completed keyexchange"
Jul 22 02:33:53 rpi-volumio-te go-librespot[7510]: time="2024-07-22T02:33:53+02:00" level=debug msg="completed challenge"
Jul 22 02:34:00 rpi-volumio-te go-librespot[7510]: time="2024-07-22T02:34:00+02:00" level=debug msg="authenticated as tenex24"
Jul 22 02:34:16 rpi-volumio-te go-librespot[7510]: time="2024-07-22T02:34:16+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed requesting login5 endpoint: failed requesting login5: Post \"https://login5.spotify.com/v3/login\": net/http: TLS handshake timeout"
Jul 22 02:34:16 rpi-volumio-te systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 22 02:34:16 rpi-volumio-te systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 22 02:34:16 rpi-volumio-te volumio[846]: (node:846) UnhandledPromiseRejectionWarning: Error: socket hang up
Jul 22 02:34:16 rpi-volumio-te volumio[846]: at connResetException (internal/errors.js:607:14)
Jul 22 02:34:16 rpi-volumio-te volumio[846]: at Socket.socketOnEnd (_http_client.js:493:23)
Jul 22 02:34:16 rpi-volumio-te volumio[846]: at Socket.emit (events.js:327:22)
Jul 22 02:34:16 rpi-volumio-te volumio[846]: at endReadableNT (internal/streams/readable.js:1327:12)
Jul 22 02:34:16 rpi-volumio-te volumio[846]: at processTicksAndRejections (internal/process/task_queues.js:80:21)
Jul 22 02:34:16 rpi-volumio-te volumio[846]: (node:846) 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: 1243)
Jul 22 02:34:16 rpi-volumio-te volumio[846]: info: Connection to go-librespot Websocket closed
Jul 22 02:34:16 rpi-volumio-te volumio[846]: info: Adding Push Notification url
Jul 22 02:34:19 rpi-volumio-te volumio[846]: info: Initializing connection to go-librespot Websocket
Jul 22 02:34:19 rpi-volumio-te volumio[846]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 22 02:34:19 rpi-volumio-te systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 22 02:34:19 rpi-volumio-te systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 152932.
Jul 22 02:34:19 rpi-volumio-te systemd[1]: Stopped go-librespot Daemon.
Jul 22 02:34:19 rpi-volumio-te systemd[1]: Started go-librespot Daemon.
Jul 22 02:34:19 rpi-volumio-te go-librespot[7559]: Librespot-go daemon starting...
Jul 22 02:34:19 rpi-volumio-te go-librespot[7559]: time="2024-07-22T02:34:19+02:00" level=info msg="generated new device id: 06d2bd1d5dba055a76a71a0f349b8d2a4dfc3faa"
Jul 22 02:34:19 rpi-volumio-te go-librespot[7559]: time="2024-07-22T02:34:19+02:00" level=debug msg="stored credentials found for tenex24"
Jul 22 02:34:19 rpi-volumio-te volumio[846]: info: Getting Push Notification urls
Jul 22 02:34:22 rpi-volumio-te volumio[846]: info: Initializing connection to go-librespot Websocket
Jul 22 02:34:22 rpi-volumio-te go-librespot[7559]: time="2024-07-22T02:34:22+02:00" level=debug msg="new websocket client"
Jul 22 02:34:22 rpi-volumio-te volumio[846]: info: Connection to go-librespot Websocket established
Jul 22 02:34:25 rpi-volumio-te volumio[846]: info: Getting Spotify volume
Jul 22 02:34:25 rpi-volumio-te volumio[846]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 5
Jul 22 02:34:25 rpi-volumio-te volumio[846]: info: CoreCommandRouter::volumioGetState
Jul 22 02:34:25 rpi-volumio-te volumio[846]: info: CorePlayQueue::getTrack 0
Jul 22 02:34:25 rpi-volumio-te volumio[846]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25
Jul 22 02:34:28 rpi-volumio-te volumio[846]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Jul 22 02:34:28 rpi-volumio-te volumio[846]: [t [Error]: A network error (such as timeout, interrupted connection or unreachable host) has occurred.] {
Jul 22 02:34:28 rpi-volumio-te volumio[846]: code: 'auth/network-request-failed',
Jul 22 02:34:28 rpi-volumio-te volumio[846]: a: null
Jul 22 02:34:28 rpi-volumio-te volumio[846]: }
Jul 22 02:34:28 rpi-volumio-te volumio[846]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Jul 22 02:34:29 rpi-volumio-te sudo[7575]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-07-22 02:33
Jul 22 02:34:29 rpi-volumio-te sudo[7575]: 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="e7445fab547cd22e23d9bef72406cfb610bc1d7d"
VOLUMIO_FE_VERSION="5d5e99f8f803b3ec5fc5e8ca13bb4023600f3eee"
VOLUMIO_FE3_VERSION="a6ae210575eae1ff43f06ab71e1cd17576840623"
VOLUMIO_BE_VERSION="a9e1e1dd6072ffb15c0fcb8938d9ea0d8900c0da"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Wed 24 Apr 2024 02:10:14 PM CEST"
VOLUMIO_VERSION="3.661"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="5bdefd4af4423fd17aacb83a8538bf1f"