-- Logs begin at Sat 2024-10-12 15:47:52 CEST, end at Fri 2024-11-01 17:19:59 CET. -- Nov 01 17:18:03 wohnzimmerspieler go-librespot[6830]: time="2024-11-01T17:18:03+01:00" level=fatal msg="failed running with username and spotify token" error="failed connecting to dealer: failed to WebSocket dial: failed to send handshake request: Get \"https://gew4-dealer.spotify.com:443/?access_token=BQAA9cxDyoThAajvjTVRYGZ8JKuff77OZ0UKjjQ83ZV_f7_mVVzSbIAjKe5aOe7e7KOfaDG4Kj-PbYzzo8NPsQJ0DOH_ZX5gyoV7PxoyunhSyL99sV06Lbx2yiufNovch7YwfUZUvslFsxDy_LA7UmEmcqxIkDe60sIwnLkIDbsoxI_CI10mLNrWAr6f8j5j6iU1savVZ7MVCZz485bxJtwC5c5PA34YuZ62_npV8CaRNg5WHgju0ttzF9BjplafwFDj_H7sZgLfmdmZtGyajTt1yjyQamGbFq24F0bZ6olAAWSZniUyXOSbOgNlKMsexUUSdtYLBkeYRC1n92ttidKzoWQJs7jxFOyEvaaAbCopWpRtKZmHsg8G8W0LRnBzFw\": context deadline exceeded" Nov 01 17:18:03 wohnzimmerspieler systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 17:18:03 wohnzimmerspieler systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 17:18:03 wohnzimmerspieler volumio[981]: (node:981) UnhandledPromiseRejectionWarning: Error: socket hang up Nov 01 17:18:03 wohnzimmerspieler volumio[981]: at connResetException (internal/errors.js:607:14) Nov 01 17:18:03 wohnzimmerspieler volumio[981]: at Socket.socketOnEnd (_http_client.js:493:23) Nov 01 17:18:03 wohnzimmerspieler volumio[981]: at Socket.emit (events.js:327:22) Nov 01 17:18:03 wohnzimmerspieler volumio[981]: at endReadableNT (internal/streams/readable.js:1327:12) Nov 01 17:18:03 wohnzimmerspieler volumio[981]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Nov 01 17:18:03 wohnzimmerspieler volumio[981]: (node:981) 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: 47409) Nov 01 17:18:03 wohnzimmerspieler volumio[981]: info: Connection to go-librespot Websocket closed Nov 01 17:18:06 wohnzimmerspieler volumio[981]: info: Initializing connection to go-librespot Websocket Nov 01 17:18:06 wohnzimmerspieler volumio[981]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 17:18:06 wohnzimmerspieler systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 01 17:18:06 wohnzimmerspieler systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21550. Nov 01 17:18:06 wohnzimmerspieler systemd[1]: Stopped go-librespot Daemon. Nov 01 17:18:06 wohnzimmerspieler systemd[1]: Started go-librespot Daemon. Nov 01 17:18:06 wohnzimmerspieler go-librespot[6879]: Librespot-go daemon starting... Nov 01 17:18:06 wohnzimmerspieler go-librespot[6879]: time="2024-11-01T17:18:06+01:00" level=info msg="generated new device id: 75cc31226af37b7a84ad830a096549ecd6d02f91" Nov 01 17:18:06 wohnzimmerspieler go-librespot[6879]: time="2024-11-01T17:18:06+01:00" level=debug msg="stored credentials found for 85pvwj1haxiwidv8ehm4qwmxv" Nov 01 17:18:09 wohnzimmerspieler volumio[981]: info: Initializing connection to go-librespot Websocket Nov 01 17:18:09 wohnzimmerspieler go-librespot[6879]: time="2024-11-01T17:18:09+01:00" level=debug msg="new websocket client" Nov 01 17:18:09 wohnzimmerspieler volumio[981]: info: Connection to go-librespot Websocket established Nov 01 17:18:12 wohnzimmerspieler volumio[981]: info: Getting Spotify volume Nov 01 17:18:12 wohnzimmerspieler volumio[981]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Nov 01 17:18:12 wohnzimmerspieler volumio[981]: info: CoreCommandRouter::volumioGetState Nov 01 17:18:12 wohnzimmerspieler volumio[981]: info: CorePlayQueue::getTrack 0 Nov 01 17:18:15 wohnzimmerspieler go-librespot[6879]: time="2024-11-01T17:18:15+01:00" level=debug msg="obtained new client token: AAD21B+ChduyV1EK8sHmZUPrBZLZICClbXgzlFHThXr+fZ/joQrwBbS1o5Mg4KtuCPNudIJGoz3GySNK5iMRskZaPZp8Y1jZbEMOSWfGoJ+UefLVVBNmAQ9zZI7rXhJk+2/Dl9ro68G4CzcP5L16T+lys4xiVEH9et990R71zDKkA6FmlT6oXTSXuntcNCGatQhc8lK7AjszIUwrEPK+8SztqQLSXrki1xgiL7DDRZwimNm3FBuzCqrw" Nov 01 17:18:29 wohnzimmerspieler go-librespot[6879]: time="2024-11-01T17:18:29+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting accesspoint from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint\": net/http: TLS handshake timeout" Nov 01 17:18:29 wohnzimmerspieler systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 17:18:29 wohnzimmerspieler systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 17:18:29 wohnzimmerspieler volumio[981]: (node:981) UnhandledPromiseRejectionWarning: Error: socket hang up Nov 01 17:18:29 wohnzimmerspieler volumio[981]: at connResetException (internal/errors.js:607:14) Nov 01 17:18:29 wohnzimmerspieler volumio[981]: at Socket.socketOnEnd (_http_client.js:493:23) Nov 01 17:18:29 wohnzimmerspieler volumio[981]: at Socket.emit (events.js:327:22) Nov 01 17:18:29 wohnzimmerspieler volumio[981]: at endReadableNT (internal/streams/readable.js:1327:12) Nov 01 17:18:29 wohnzimmerspieler volumio[981]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Nov 01 17:18:29 wohnzimmerspieler volumio[981]: (node:981) 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: 47410) Nov 01 17:18:29 wohnzimmerspieler volumio[981]: info: Connection to go-librespot Websocket closed Nov 01 17:18:32 wohnzimmerspieler volumio[981]: info: Initializing connection to go-librespot Websocket Nov 01 17:18:32 wohnzimmerspieler volumio[981]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 17:18:32 wohnzimmerspieler systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 01 17:18:32 wohnzimmerspieler systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21551. Nov 01 17:18:32 wohnzimmerspieler systemd[1]: Stopped go-librespot Daemon. Nov 01 17:18:32 wohnzimmerspieler systemd[1]: Started go-librespot Daemon. Nov 01 17:18:32 wohnzimmerspieler go-librespot[6888]: Librespot-go daemon starting... Nov 01 17:18:32 wohnzimmerspieler go-librespot[6888]: time="2024-11-01T17:18:32+01:00" level=info msg="generated new device id: 204044cd2b0598c8835793cea377ab491e64bfc9" Nov 01 17:18:32 wohnzimmerspieler go-librespot[6888]: time="2024-11-01T17:18:32+01:00" level=debug msg="stored credentials found for 85pvwj1haxiwidv8ehm4qwmxv" Nov 01 17:18:35 wohnzimmerspieler volumio[981]: info: Initializing connection to go-librespot Websocket Nov 01 17:18:35 wohnzimmerspieler volumio[981]: info: Connection to go-librespot Websocket established Nov 01 17:18:35 wohnzimmerspieler go-librespot[6888]: time="2024-11-01T17:18:35+01:00" level=debug msg="new websocket client" Nov 01 17:18:38 wohnzimmerspieler volumio[981]: info: Getting Spotify volume Nov 01 17:18:38 wohnzimmerspieler volumio[981]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Nov 01 17:18:38 wohnzimmerspieler volumio[981]: info: CoreCommandRouter::volumioGetState Nov 01 17:18:38 wohnzimmerspieler volumio[981]: info: CorePlayQueue::getTrack 0 Nov 01 17:18:44 wohnzimmerspieler go-librespot[6888]: time="2024-11-01T17:18:44+01:00" level=debug msg="obtained new client token: AABq6xEBjmcTFkQ316F36E8zHE+HAFEdLg8sMsSBPSBwFS8hwf3qvExAt+0lEuyy+6P2STdit8+X59/6aAg65EPbpteLD1/f/ONSQxsiFq0JEdYdEsDt0/aeQcGOfPE6VGV7ZaLJa3gFgL/5RYzIszndXpesdWEACcZu0UFafMqYSB2/fYBMFxOgLCdcthQzOiLHa1almDqIeldBg+HmsDCMgOQ2X2s9jLxvIJT6gDhMoOVapQ1iXbhtbvU=" Nov 01 17:18:52 wohnzimmerspieler go-librespot[6888]: time="2024-11-01T17:18:52+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Nov 01 17:18:58 wohnzimmerspieler go-librespot[6888]: time="2024-11-01T17:18:58+01:00" level=debug msg="completed keyexchange" Nov 01 17:18:59 wohnzimmerspieler go-librespot[6888]: time="2024-11-01T17:18:59+01:00" level=debug msg="completed challenge" Nov 01 17:18:59 wohnzimmerspieler go-librespot[6888]: time="2024-11-01T17:18:59+01:00" level=debug msg="authenticated as 85pvwj1haxiwidv8ehm4qwmxv" Nov 01 17:19:29 wohnzimmerspieler go-librespot[6888]: time="2024-11-01T17:19:29+01:00" level=debug msg="authenticated as 85pvwj1haxiwidv8ehm4qwmxv" Nov 01 17:19:29 wohnzimmerspieler go-librespot[6888]: time="2024-11-01T17:19:29+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Nov 01 17:19:29 wohnzimmerspieler go-librespot[6888]: time="2024-11-01T17:19:29+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 01 17:19:36 wohnzimmerspieler go-librespot[6888]: time="2024-11-01T17:19:36+01:00" level=debug msg="dealer connection opened" Nov 01 17:19:36 wohnzimmerspieler go-librespot[6888]: time="2024-11-01T17:19:36+01:00" level=error msg="failed sending Pong packet" error="failed writing packet: write tcp 192.168.178.155:47758->34.158.1.133:4070: write: connection reset by peer" Nov 01 17:19:36 wohnzimmerspieler volumio[981]: info: Spotify volume: 100 Nov 01 17:19:36 wohnzimmerspieler go-librespot[6888]: time="2024-11-01T17:19:36+01:00" level=debug msg="received connection id: ZmQwYzEyZTUtOTViZS00MWVmLTkzMGQtNDU5NjEwNmNlZTlkK2RlYWxlcit0Y3A6Ly8wYWNhNThlNC5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArNENDNzdGRUNFN0E1ODI5NkZEODhCN0M4NkY1NDc0ODFCRTU0NjU4MTFENkZBRjg1NERDRTAwOTdDMzM0MjJDMA==" Nov 01 17:19:42 wohnzimmerspieler go-librespot[6888]: time="2024-11-01T17:19:42+01:00" level=debug msg="completed keyexchange" Nov 01 17:19:43 wohnzimmerspieler go-librespot[6888]: time="2024-11-01T17:19:43+01:00" level=debug msg="completed challenge" Nov 01 17:19:46 wohnzimmerspieler go-librespot[6888]: time="2024-11-01T17:19:46+01:00" level=debug msg="authenticated as 85pvwj1haxiwidv8ehm4qwmxv" Nov 01 17:19:46 wohnzimmerspieler go-librespot[6888]: time="2024-11-01T17:19:46+01:00" level=debug msg="re-established accesspoint connection" Nov 01 17:19:46 wohnzimmerspieler go-librespot[6888]: time="2024-11-01T17:19:46+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Nov 01 17:19:46 wohnzimmerspieler go-librespot[6888]: time="2024-11-01T17:19:46+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Nov 01 17:19:59 wohnzimmerspieler volumio[981]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 01 17:19:59 wohnzimmerspieler volumio[981]: [t [Error]: A network error (such as timeout, interrupted connection or unreachable host) has occurred.] { Nov 01 17:19:59 wohnzimmerspieler volumio[981]: code: 'auth/network-request-failed', Nov 01 17:19:59 wohnzimmerspieler volumio[981]: a: null Nov 01 17:19:59 wohnzimmerspieler volumio[981]: } Nov 01 17:19:59 wohnzimmerspieler volumio[981]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 01 17:19:59 wohnzimmerspieler sudo[6948]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-11-01 17:18 Nov 01 17:19:59 wohnzimmerspieler sudo[6948]: 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="5fd3886148e72a9cecd88a772d1f6079fb64d11a" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8bb23b009e91ae4c7ecd678f193e7d3b281fca0c" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 22 Jul 2024 07:17:01 PM CEST" VOLUMIO_VERSION="3.742" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="2782e52360f70dfab079c82951ebbbb1"