-- Logs begin at Thu 2019-02-14 18:12:00 CST, end at Wed 2025-03-19 19:55:27 CST. -- Mar 19 19:54:02 volumio go-librespot[2153]: time="2025-03-19T19:54:02+08:00" level=debug msg="completed keyexchange" Mar 19 19:54:03 volumio go-librespot[2153]: time="2025-03-19T19:54:03+08:00" level=debug msg="completed challenge" Mar 19 19:54:03 volumio go-librespot[2153]: time="2025-03-19T19:54:03+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Mar 19 19:54:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 19 19:54:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 19 19:54:03 volumio volumio[864]: (node:864) UnhandledPromiseRejectionWarning: Error: socket hang up Mar 19 19:54:03 volumio volumio[864]: at connResetException (internal/errors.js:607:14) Mar 19 19:54:03 volumio volumio[864]: at Socket.socketOnEnd (_http_client.js:493:23) Mar 19 19:54:03 volumio volumio[864]: at Socket.emit (events.js:327:22) Mar 19 19:54:03 volumio volumio[864]: at endReadableNT (internal/streams/readable.js:1327:12) Mar 19 19:54:03 volumio volumio[864]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Mar 19 19:54:03 volumio volumio[864]: (node:864) 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: 13) Mar 19 19:54:03 volumio volumio[864]: info: Connection to go-librespot Websocket closed Mar 19 19:54:06 volumio volumio[864]: info: Initializing connection to go-librespot Websocket Mar 19 19:54:06 volumio volumio[864]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 19 19:54:06 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 19 19:54:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Mar 19 19:54:06 volumio systemd[1]: Stopped go-librespot Daemon. Mar 19 19:54:06 volumio systemd[1]: Started go-librespot Daemon. Mar 19 19:54:06 volumio go-librespot[2163]: Librespot-go daemon starting... Mar 19 19:54:06 volumio go-librespot[2163]: time="2025-03-19T19:54:06+08:00" level=info msg="generated new device id: 1512deacb01ac1ef7cc117b7f8945241b07d6a11" Mar 19 19:54:06 volumio go-librespot[2163]: time="2025-03-19T19:54:06+08:00" level=debug msg="stored credentials not found" Mar 19 19:54:09 volumio volumio[864]: info: Initializing connection to go-librespot Websocket Mar 19 19:54:09 volumio go-librespot[2163]: time="2025-03-19T19:54:09+08:00" level=debug msg="new websocket client" Mar 19 19:54:09 volumio volumio[864]: info: Connection to go-librespot Websocket established Mar 19 19:54:12 volumio volumio[864]: info: Getting Spotify volume Mar 19 19:54:12 volumio volumio[864]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 11 Mar 19 19:54:12 volumio go-librespot[2163]: time="2025-03-19T19:54:12+08:00" level=debug msg="obtained new client token: AADsAVRcRWCY6f3QTubAqSqHNZTzOgVCurSYvtQ8Rhmg7jIKVO5cbvPOidBdaAddoDh/ISbeSdZ3SF21Ij+7121DYbHxZJF4L2oNJt/SBqbCDxNk1LyDUaXxIi3bFT7D6YZjKrmVVTDvD9SlyuGV2Eu5C42z5yEE1bxytHdd7+rg2N1hNTRWpifL5rTJPnVOCEFmsL/gC+9Th/GoxNCJxmcPQoFQ3KV+3tqd0WJq2WX2IWcC/z+tvzRS82MSaw==" Mar 19 19:54:12 volumio volumio[864]: info: CoreCommandRouter::volumioGetState Mar 19 19:54:12 volumio volumio[864]: info: CorePlayQueue::getTrack 65 Mar 19 19:54:12 volumio volumio[864]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Mar 19 19:54:18 volumio go-librespot[2163]: time="2025-03-19T19:54:18+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 19 19:54:23 volumio go-librespot[2163]: time="2025-03-19T19:54:23+08:00" level=debug msg="completed keyexchange" Mar 19 19:54:24 volumio go-librespot[2163]: time="2025-03-19T19:54:24+08:00" level=debug msg="completed challenge" Mar 19 19:54:24 volumio go-librespot[2163]: time="2025-03-19T19:54:24+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Mar 19 19:54:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 19 19:54:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 19 19:54:24 volumio volumio[864]: (node:864) UnhandledPromiseRejectionWarning: Error: socket hang up Mar 19 19:54:24 volumio volumio[864]: at connResetException (internal/errors.js:607:14) Mar 19 19:54:24 volumio volumio[864]: at Socket.socketOnEnd (_http_client.js:493:23) Mar 19 19:54:24 volumio volumio[864]: at Socket.emit (events.js:327:22) Mar 19 19:54:24 volumio volumio[864]: at endReadableNT (internal/streams/readable.js:1327:12) Mar 19 19:54:24 volumio volumio[864]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Mar 19 19:54:24 volumio volumio[864]: (node:864) 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: 14) Mar 19 19:54:24 volumio volumio[864]: info: Connection to go-librespot Websocket closed Mar 19 19:54:27 volumio volumio[864]: info: Initializing connection to go-librespot Websocket Mar 19 19:54:27 volumio volumio[864]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 19 19:54:27 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 19 19:54:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Mar 19 19:54:27 volumio systemd[1]: Stopped go-librespot Daemon. Mar 19 19:54:27 volumio systemd[1]: Started go-librespot Daemon. Mar 19 19:54:27 volumio go-librespot[2174]: Librespot-go daemon starting... Mar 19 19:54:27 volumio go-librespot[2174]: time="2025-03-19T19:54:27+08:00" level=info msg="generated new device id: 8e31c57f376d4cb23ae0e0ed0ef61fba775d90f4" Mar 19 19:54:27 volumio go-librespot[2174]: time="2025-03-19T19:54:27+08:00" level=debug msg="stored credentials not found" Mar 19 19:54:30 volumio volumio[864]: info: Initializing connection to go-librespot Websocket Mar 19 19:54:30 volumio go-librespot[2174]: time="2025-03-19T19:54:30+08:00" level=debug msg="new websocket client" Mar 19 19:54:30 volumio volumio[864]: info: Connection to go-librespot Websocket established Mar 19 19:54:33 volumio volumio[864]: info: Getting Spotify volume Mar 19 19:54:33 volumio volumio[864]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Mar 19 19:54:33 volumio volumio[864]: info: CoreCommandRouter::volumioGetState Mar 19 19:54:33 volumio volumio[864]: info: CorePlayQueue::getTrack 65 Mar 19 19:54:33 volumio volumio[864]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Mar 19 19:54:33 volumio go-librespot[2174]: time="2025-03-19T19:54:33+08:00" level=debug msg="obtained new client token: AAAdtbsxVocWVHeFbGkljIncin5XIkZXvkckQU6mViNBse6SM5hSxrrcJKR/Eel5+Z42TFHTPpskRYSFkmrl8T76019orrVdLUs9JImtOKnx0FErIRoY8z/vhL0r78vCIBy8GxnFMLBk+RUdwt1uoE7CNMh7MrEStGRIV6l8R0Qjz4bOYvgttUGbaaW7JManrM43Yopz1xL8Xc3FwfglNIqP06bAmR2fSDnnYXLfSNe30bfrLOsoLEA6GXks8w==" Mar 19 19:54:39 volumio go-librespot[2174]: time="2025-03-19T19:54:39+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 19 19:54:44 volumio go-librespot[2174]: time="2025-03-19T19:54:44+08:00" level=debug msg="completed keyexchange" Mar 19 19:54:44 volumio go-librespot[2174]: time="2025-03-19T19:54:44+08:00" level=debug msg="completed challenge" Mar 19 19:54:44 volumio go-librespot[2174]: time="2025-03-19T19:54:44+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Mar 19 19:54:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 19 19:54:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 19 19:54:44 volumio volumio[864]: (node:864) UnhandledPromiseRejectionWarning: Error: socket hang up Mar 19 19:54:44 volumio volumio[864]: at connResetException (internal/errors.js:607:14) Mar 19 19:54:44 volumio volumio[864]: at Socket.socketOnEnd (_http_client.js:493:23) Mar 19 19:54:44 volumio volumio[864]: at Socket.emit (events.js:327:22) Mar 19 19:54:44 volumio volumio[864]: at endReadableNT (internal/streams/readable.js:1327:12) Mar 19 19:54:44 volumio volumio[864]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Mar 19 19:54:44 volumio volumio[864]: (node:864) 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: 15) Mar 19 19:54:44 volumio volumio[864]: info: Connection to go-librespot Websocket closed Mar 19 19:54:47 volumio volumio[864]: info: Initializing connection to go-librespot Websocket Mar 19 19:54:47 volumio volumio[864]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 19 19:54:48 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 19 19:54:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Mar 19 19:54:48 volumio systemd[1]: Stopped go-librespot Daemon. Mar 19 19:54:48 volumio systemd[1]: Started go-librespot Daemon. Mar 19 19:54:48 volumio go-librespot[2227]: Librespot-go daemon starting... Mar 19 19:54:48 volumio go-librespot[2227]: time="2025-03-19T19:54:48+08:00" level=info msg="generated new device id: f0db4f714644d1b81a099511ac86bc0978f212fa" Mar 19 19:54:48 volumio go-librespot[2227]: time="2025-03-19T19:54:48+08:00" level=debug msg="stored credentials not found" Mar 19 19:54:50 volumio volumio[864]: info: Initializing connection to go-librespot Websocket Mar 19 19:54:50 volumio go-librespot[2227]: time="2025-03-19T19:54:50+08:00" level=debug msg="new websocket client" Mar 19 19:54:50 volumio volumio[864]: info: Connection to go-librespot Websocket established Mar 19 19:54:53 volumio volumio[864]: info: Getting Spotify volume Mar 19 19:54:53 volumio volumio[864]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Mar 19 19:54:54 volumio volumio[864]: info: CoreCommandRouter::volumioGetState Mar 19 19:54:54 volumio volumio[864]: info: CorePlayQueue::getTrack 65 Mar 19 19:54:54 volumio volumio[864]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Mar 19 19:54:54 volumio go-librespot[2227]: time="2025-03-19T19:54:54+08:00" level=debug msg="obtained new client token: AABxpN/0+r73uO7l1E4RhGY3cvXnjnD0v/5wW05TpfDLGSlLHk/guE5nLg4tSC4wKOkPYI3B3jNQvWyxynYyl063/Rv2vIojMVKxussz/s3TS76swKLFsNGAhfP+ql9avZkK3x7fQaN/OwKWkqCLAXbBV+YUEly1Dek5kFObqXNSphN0AAA5uZNjsIA3flrssI8+aVpDtt5g+nJGc0KjWarATvbmvYACFeqgUCretKvxxUvz3uRdoLaRLKvVpOQK" Mar 19 19:54:59 volumio go-librespot[2227]: time="2025-03-19T19:54:59+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 19 19:55:05 volumio go-librespot[2227]: time="2025-03-19T19:55:05+08:00" level=debug msg="completed keyexchange" Mar 19 19:55:05 volumio go-librespot[2227]: time="2025-03-19T19:55:05+08:00" level=debug msg="completed challenge" Mar 19 19:55:06 volumio go-librespot[2227]: time="2025-03-19T19:55:06+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Mar 19 19:55:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 19 19:55:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 19 19:55:06 volumio volumio[864]: (node:864) UnhandledPromiseRejectionWarning: Error: socket hang up Mar 19 19:55:06 volumio volumio[864]: at connResetException (internal/errors.js:607:14) Mar 19 19:55:06 volumio volumio[864]: at Socket.socketOnEnd (_http_client.js:493:23) Mar 19 19:55:06 volumio volumio[864]: at Socket.emit (events.js:327:22) Mar 19 19:55:06 volumio volumio[864]: at endReadableNT (internal/streams/readable.js:1327:12) Mar 19 19:55:06 volumio volumio[864]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Mar 19 19:55:06 volumio volumio[864]: (node:864) 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: 16) Mar 19 19:55:06 volumio volumio[864]: info: Connection to go-librespot Websocket closed Mar 19 19:55:09 volumio volumio[864]: info: Initializing connection to go-librespot Websocket Mar 19 19:55:09 volumio volumio[864]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 19 19:55:09 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 19 19:55:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Mar 19 19:55:09 volumio systemd[1]: Stopped go-librespot Daemon. Mar 19 19:55:09 volumio systemd[1]: Started go-librespot Daemon. Mar 19 19:55:09 volumio go-librespot[2240]: Librespot-go daemon starting... Mar 19 19:55:09 volumio go-librespot[2240]: time="2025-03-19T19:55:09+08:00" level=info msg="generated new device id: 839d5d82caf0caafa251ddc3c0a5b2936a4aff9f" Mar 19 19:55:09 volumio go-librespot[2240]: time="2025-03-19T19:55:09+08:00" level=debug msg="stored credentials not found" Mar 19 19:55:12 volumio volumio[864]: info: Initializing connection to go-librespot Websocket Mar 19 19:55:12 volumio go-librespot[2240]: time="2025-03-19T19:55:12+08:00" level=debug msg="new websocket client" Mar 19 19:55:12 volumio volumio[864]: info: Connection to go-librespot Websocket established Mar 19 19:55:15 volumio volumio[864]: info: Getting Spotify volume Mar 19 19:55:15 volumio volumio[864]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Mar 19 19:55:15 volumio volumio[864]: info: CoreCommandRouter::volumioGetState Mar 19 19:55:15 volumio volumio[864]: info: CorePlayQueue::getTrack 65 Mar 19 19:55:15 volumio volumio[864]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Mar 19 19:55:15 volumio go-librespot[2240]: time="2025-03-19T19:55:15+08:00" level=debug msg="obtained new client token: AABYxK7KRiuXQk2jR0SwH5zaicnFMmTz+vwWCJ0kBM8+nQ1ajzAiDDOghVDnHzFQ+bKvLijcp2E7qMKYDBU8XoMx3jU04yACOQAJvURnl6GGp1fbHcCo6/nSaksCErr0DVHQsLfmU7Seo1uTNsHsZLq/RlKdNLkOE5kUqrO1KmYlBhC/y5kuv3GXSFdnVlh9k6NNazCDuQ9LqtiJqKeNMZSCmjz0s6trQ2mWgfSN/BaYjpUljLmdqgZw35DKrA0x" Mar 19 19:55:16 volumio kernel: hwmon hwmon1: Undervoltage detected! Mar 19 19:55:22 volumio kernel: hwmon hwmon1: Voltage normalised Mar 19 19:55:27 volumio volumio[864]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 19 19:55:27 volumio volumio[864]: Error: connect ETIMEDOUT 208.101.21.43:443 Mar 19 19:55:27 volumio volumio[864]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) { Mar 19 19:55:27 volumio volumio[864]: errno: -110, Mar 19 19:55:27 volumio volumio[864]: code: 'ETIMEDOUT', Mar 19 19:55:27 volumio volumio[864]: syscall: 'connect', Mar 19 19:55:27 volumio volumio[864]: address: '208.101.21.43', Mar 19 19:55:27 volumio volumio[864]: port: 443 Mar 19 19:55:27 volumio volumio[864]: } Mar 19 19:55:27 volumio volumio[864]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 19 19:55:27 volumio sudo[2262]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-03-19 19:54 Mar 19 19:55:27 volumio sudo[2262]: 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"