-- Logs begin at Sat 2024-03-16 22:06:54 CST, end at Sat 2024-03-30 22:51:30 CST. -- Mar 30 22:50:00 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Mar 30 22:50:00 volumio volumio[898]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 30 22:50:00 volumio kernel: usb 1-1.4.3: USB disconnect, device number 17 Mar 30 22:50:00 volumio volumio[898]: info: No valid Plugin REST Endpoint Mar 30 22:50:01 volumio kernel: usb 1-1.4.3: new full-speed USB device number 18 using xhci_hcd Mar 30 22:50:01 volumio kernel: usb 1-1.4.3: New USB device found, idVendor=8087, idProduct=1024, bcdDevice= 1.00 Mar 30 22:50:01 volumio kernel: usb 1-1.4.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Mar 30 22:50:01 volumio kernel: usb 1-1.4.3: Product: USB PnP Audio Device Mar 30 22:50:01 volumio kernel: usb 1-1.4.3: Manufacturer: BlueTrm Mar 30 22:50:01 volumio kernel: usb 1-1.4.3: SerialNumber: 20170726905923 Mar 30 22:50:01 volumio kernel: usb 1-1.4.3: 5:0: bogus dB values (-12800/-12700), disabling dB reporting Mar 30 22:50:01 volumio volumio[898]: info: No valid Plugin REST Endpoint Mar 30 22:50:02 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 30 22:50:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 210. Mar 30 22:50:02 volumio systemd[1]: Stopped go-librespot Daemon. Mar 30 22:50:02 volumio systemd[1]: Started go-librespot Daemon. Mar 30 22:50:02 volumio go-librespot[11093]: Librespot-go daemon starting... Mar 30 22:50:02 volumio go-librespot[11093]: time="2024-03-30T22:50:02+08:00" level=info msg="generated new device id: 16d30661ae6a212aa309ddafa7204fe1b7a1dd1c" Mar 30 22:50:02 volumio go-librespot[11093]: time="2024-03-30T22:50:02+08:00" level=debug msg="stored credentials not found" Mar 30 22:50:03 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Mar 30 22:50:03 volumio go-librespot[11093]: time="2024-03-30T22:50:03+08:00" level=debug msg="new websocket client" Mar 30 22:50:03 volumio volumio[898]: info: Connection to go-librespot Websocket established Mar 30 22:50:03 volumio go-librespot[11093]: time="2024-03-30T22:50:03+08:00" level=debug msg="obtained new client token: AACNXQ8gVpvt3c90XDtgOTuDaeBkvWDj1tW0jjOwd6kmr67r2W9/oo/uX9EztPAzBAi3dSVsZKwegZCqaGNDoLXNYPpFrCEM6BiXKeGlAxg9qI3Zo/Di/+tTfBwS9Q6Fo08GwpA+4wN8ABFA+VxWbXVBX/xk7RWudl+t6x52XYsvsnfBOTdHGS2YQXW4h6Dn+9M+Q1fYrxMsVOY5NWYucr+da0edkXKUECFSJKgtMlJXRkWjWi9UZyI/wCvj9HoU" Mar 30 22:50:04 volumio go-librespot[11093]: time="2024-03-30T22:50:04+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 30 22:50:04 volumio go-librespot[11093]: time="2024-03-30T22:50:04+08:00" level=debug msg="completed keyexchange" Mar 30 22:50:04 volumio go-librespot[11093]: time="2024-03-30T22:50:04+08:00" level=debug msg="completed challenge" Mar 30 22:50:04 volumio go-librespot[11093]: time="2024-03-30T22:50:04+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 30 22:50:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 30 22:50:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 30 22:50:04 volumio volumio[898]: info: Connection to go-librespot Websocket closed Mar 30 22:50:06 volumio kernel: usb 1-1.4.3: USB disconnect, device number 18 Mar 30 22:50:06 volumio volumio[898]: info: Getting Spotify volume Mar 30 22:50:06 volumio volumio[898]: (node:898) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 30 22:50:06 volumio volumio[898]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 30 22:50:06 volumio volumio[898]: (node:898) 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: 113) Mar 30 22:50:06 volumio volumio[898]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Mar 30 22:50:06 volumio volumio[898]: info: CoreCommandRouter::volumioGetState Mar 30 22:50:06 volumio volumio[898]: info: CorePlayQueue::getTrack 234 Mar 30 22:50:06 volumio volumio[898]: SPOTIFY: RECEIVED VOLUMIO VOLUME 97 Mar 30 22:50:06 volumio volumio[898]: info: No valid Plugin REST Endpoint Mar 30 22:50:06 volumio kernel: usb 1-1.4.3: new full-speed USB device number 19 using xhci_hcd Mar 30 22:50:07 volumio kernel: usb 1-1.4.3: New USB device found, idVendor=8087, idProduct=1024, bcdDevice= 1.00 Mar 30 22:50:07 volumio kernel: usb 1-1.4.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Mar 30 22:50:07 volumio kernel: usb 1-1.4.3: Product: USB PnP Audio Device Mar 30 22:50:07 volumio kernel: usb 1-1.4.3: Manufacturer: BlueTrm Mar 30 22:50:07 volumio kernel: usb 1-1.4.3: SerialNumber: 20170726905923 Mar 30 22:50:07 volumio kernel: usb 1-1.4.3: 5:0: bogus dB values (-12800/-12700), disabling dB reporting Mar 30 22:50:07 volumio volumio[898]: info: No valid Plugin REST Endpoint Mar 30 22:50:07 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Mar 30 22:50:07 volumio volumio[898]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 30 22:50:08 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 30 22:50:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 211. Mar 30 22:50:08 volumio systemd[1]: Stopped go-librespot Daemon. Mar 30 22:50:08 volumio systemd[1]: Started go-librespot Daemon. Mar 30 22:50:08 volumio go-librespot[11119]: Librespot-go daemon starting... Mar 30 22:50:08 volumio go-librespot[11119]: time="2024-03-30T22:50:08+08:00" level=info msg="generated new device id: 129182622f46e9209bdf83a34f487d29e1f166f0" Mar 30 22:50:08 volumio go-librespot[11119]: time="2024-03-30T22:50:08+08:00" level=debug msg="stored credentials not found" Mar 30 22:50:08 volumio go-librespot[11119]: time="2024-03-30T22:50:08+08:00" level=debug msg="obtained new client token: AAA/Cx59uIA7AHxth5A2CiLjlCMoGMNFJVWkXH8SW45lBQ1tJL9qDbYz/Na6/kG3sqW/qoPjr+J7ELs8Byd7ofGO6sepqI4XFv5lhJ1OfogFJKYrghiwRlztLBF7I1aE+DYy7OaXzbn9SpSppzsXXxY/fWGnAnAbduTOGx0MkQrEdjCJmd9WK+KrMhS0V4fvnEmz04Ed0KNQJGt2QGz/8HlhWYwOkN/BceCA2Gib9si8A7SBK9hr+XWxxMUcaSbK" Mar 30 22:50:09 volumio go-librespot[11119]: time="2024-03-30T22:50:09+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 30 22:50:09 volumio go-librespot[11119]: time="2024-03-30T22:50:09+08:00" level=debug msg="completed keyexchange" Mar 30 22:50:09 volumio go-librespot[11119]: time="2024-03-30T22:50:09+08:00" level=debug msg="completed challenge" Mar 30 22:50:09 volumio go-librespot[11119]: time="2024-03-30T22:50:09+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 30 22:50:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 30 22:50:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 30 22:50:10 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Mar 30 22:50:10 volumio volumio[898]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 30 22:50:12 volumio kernel: usb 1-1.4.3: USB disconnect, device number 19 Mar 30 22:50:12 volumio volumio[898]: info: No valid Plugin REST Endpoint Mar 30 22:50:12 volumio kernel: usb 1-1.4.3: new full-speed USB device number 20 using xhci_hcd Mar 30 22:50:12 volumio kernel: usb 1-1.4.3: New USB device found, idVendor=8087, idProduct=1024, bcdDevice= 1.00 Mar 30 22:50:12 volumio kernel: usb 1-1.4.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Mar 30 22:50:12 volumio kernel: usb 1-1.4.3: Product: USB PnP Audio Device Mar 30 22:50:12 volumio kernel: usb 1-1.4.3: Manufacturer: BlueTrm Mar 30 22:50:12 volumio kernel: usb 1-1.4.3: SerialNumber: 20170726905923 Mar 30 22:50:12 volumio kernel: usb 1-1.4.3: 5:0: bogus dB values (-12800/-12700), disabling dB reporting Mar 30 22:50:12 volumio volumio[898]: info: No valid Plugin REST Endpoint Mar 30 22:50:13 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 30 22:50:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 212. Mar 30 22:50:13 volumio systemd[1]: Stopped go-librespot Daemon. Mar 30 22:50:13 volumio systemd[1]: Started go-librespot Daemon. Mar 30 22:50:13 volumio go-librespot[11145]: Librespot-go daemon starting... Mar 30 22:50:13 volumio go-librespot[11145]: time="2024-03-30T22:50:13+08:00" level=info msg="generated new device id: 2237e72231f8f710289554efdf001c2cecd4f8cd" Mar 30 22:50:13 volumio go-librespot[11145]: time="2024-03-30T22:50:13+08:00" level=debug msg="stored credentials not found" Mar 30 22:50:13 volumio go-librespot[11145]: time="2024-03-30T22:50:13+08:00" level=debug msg="obtained new client token: AAAXDhhBgzspzOfDz/uBQK/iC0CQqCwdlAvtH3Cmao8JeugkLvQ8+DGbuhfAnrAroP8UdQY/iiTsvRStj32HkeKAoj5LOYSim7gta0tDMZXjQwZGDR50wUPAZcS+4q1fs/q/+AAOniDcIl8eLwNBQmyDNUwG4pb5NoRkdqKr3nzXF+fAfzWfYSdg1WQfxTiJQJaS8DPrNiMz3bQfrn0t6rzH74XigQ1pLJEmzV6rXSQn4ycjemrVloxt94KxWxvx" Mar 30 22:50:13 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Mar 30 22:50:13 volumio go-librespot[11145]: time="2024-03-30T22:50:13+08:00" level=debug msg="new websocket client" Mar 30 22:50:13 volumio volumio[898]: info: Connection to go-librespot Websocket established Mar 30 22:50:14 volumio go-librespot[11145]: time="2024-03-30T22:50:14+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 30 22:50:14 volumio go-librespot[11145]: time="2024-03-30T22:50:14+08:00" level=debug msg="completed keyexchange" Mar 30 22:50:15 volumio go-librespot[11145]: time="2024-03-30T22:50:15+08:00" level=debug msg="completed challenge" Mar 30 22:50:15 volumio go-librespot[11145]: time="2024-03-30T22:50:15+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 30 22:50:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 30 22:50:15 volumio volumio[898]: info: Connection to go-librespot Websocket closed Mar 30 22:50:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 30 22:50:16 volumio volumio[898]: info: Getting Spotify volume Mar 30 22:50:16 volumio volumio[898]: (node:898) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 30 22:50:16 volumio volumio[898]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 30 22:50:16 volumio volumio[898]: (node:898) 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: 114) Mar 30 22:50:16 volumio volumio[898]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Mar 30 22:50:16 volumio volumio[898]: info: CoreCommandRouter::volumioGetState Mar 30 22:50:16 volumio volumio[898]: info: CorePlayQueue::getTrack 234 Mar 30 22:50:16 volumio volumio[898]: SPOTIFY: RECEIVED VOLUMIO VOLUME 97 Mar 30 22:50:17 volumio kernel: usb 1-1.4.3: USB disconnect, device number 20 Mar 30 22:50:17 volumio volumio[898]: info: No valid Plugin REST Endpoint Mar 30 22:50:18 volumio kernel: usb 1-1.4.3: new full-speed USB device number 21 using xhci_hcd Mar 30 22:50:18 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Mar 30 22:50:18 volumio volumio[898]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 30 22:50:18 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 30 22:50:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 213. Mar 30 22:50:18 volumio systemd[1]: Stopped go-librespot Daemon. Mar 30 22:50:18 volumio kernel: usb 1-1.4.3: New USB device found, idVendor=8087, idProduct=1024, bcdDevice= 1.00 Mar 30 22:50:18 volumio kernel: usb 1-1.4.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Mar 30 22:50:18 volumio kernel: usb 1-1.4.3: Product: USB PnP Audio Device Mar 30 22:50:18 volumio kernel: usb 1-1.4.3: Manufacturer: BlueTrm Mar 30 22:50:18 volumio kernel: usb 1-1.4.3: SerialNumber: 20170726905923 Mar 30 22:50:18 volumio kernel: usb 1-1.4.3: 5:0: bogus dB values (-12800/-12700), disabling dB reporting Mar 30 22:50:18 volumio volumio[898]: info: No valid Plugin REST Endpoint Mar 30 22:50:18 volumio systemd[1]: Started go-librespot Daemon. Mar 30 22:50:18 volumio go-librespot[11169]: Librespot-go daemon starting... Mar 30 22:50:18 volumio go-librespot[11169]: time="2024-03-30T22:50:18+08:00" level=info msg="generated new device id: 456e3bc034c11ed8226154f586fa275f0c208d19" Mar 30 22:50:18 volumio go-librespot[11169]: time="2024-03-30T22:50:18+08:00" level=debug msg="stored credentials not found" Mar 30 22:50:19 volumio go-librespot[11169]: time="2024-03-30T22:50:19+08:00" level=debug msg="obtained new client token: AACt6UWzEoWeT3C/7Bj6R5xQ8YeYTiRSsqH7DbuowSkCuDV856zzsXDi8GnaO3AOBBFI1QHMtDPH69uqzD5+Ea5Ir//0CKqzQYBjtNv1ha2tDHzmbwkGQXtxza+dkaterIf2m4YQfB40/d4apTg6t5eefmcZPki+NG1895ayzpTW8O+ZAYFBRVgnA2SCLEM7atoItNtZHm1qeO2zXyApYqs3ogTbP4WwkCaLQVsfenlXNVbtGhO7j2aoC7hi0T0P" Mar 30 22:50:20 volumio go-librespot[11169]: time="2024-03-30T22:50:20+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 30 22:50:20 volumio go-librespot[11169]: time="2024-03-30T22:50:20+08:00" level=debug msg="completed keyexchange" Mar 30 22:50:20 volumio go-librespot[11169]: time="2024-03-30T22:50:20+08:00" level=debug msg="completed challenge" Mar 30 22:50:20 volumio go-librespot[11169]: time="2024-03-30T22:50:20+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 30 22:50:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 30 22:50:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 30 22:50:21 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Mar 30 22:50:21 volumio volumio[898]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 30 22:50:23 volumio kernel: usb 1-1.4.3: USB disconnect, device number 21 Mar 30 22:50:23 volumio volumio[898]: info: No valid Plugin REST Endpoint Mar 30 22:50:23 volumio kernel: usb 1-1.4.3: new full-speed USB device number 22 using xhci_hcd Mar 30 22:50:23 volumio kernel: usb 1-1.4.3: New USB device found, idVendor=8087, idProduct=1024, bcdDevice= 1.00 Mar 30 22:50:23 volumio kernel: usb 1-1.4.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Mar 30 22:50:23 volumio kernel: usb 1-1.4.3: Product: USB PnP Audio Device Mar 30 22:50:23 volumio kernel: usb 1-1.4.3: Manufacturer: BlueTrm Mar 30 22:50:23 volumio kernel: usb 1-1.4.3: SerialNumber: 20170726905923 Mar 30 22:50:23 volumio kernel: usb 1-1.4.3: 5:0: bogus dB values (-12800/-12700), disabling dB reporting Mar 30 22:50:24 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 30 22:50:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 214. Mar 30 22:50:24 volumio systemd[1]: Stopped go-librespot Daemon. Mar 30 22:50:24 volumio volumio[898]: info: No valid Plugin REST Endpoint Mar 30 22:50:24 volumio systemd[1]: Started go-librespot Daemon. Mar 30 22:50:24 volumio go-librespot[11200]: Librespot-go daemon starting... Mar 30 22:50:24 volumio go-librespot[11200]: time="2024-03-30T22:50:24+08:00" level=info msg="generated new device id: 91a4ede51b2ae7485963af70fb70c4f418319435" Mar 30 22:50:24 volumio go-librespot[11200]: time="2024-03-30T22:50:24+08:00" level=debug msg="stored credentials not found" Mar 30 22:50:24 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Mar 30 22:50:24 volumio go-librespot[11200]: time="2024-03-30T22:50:24+08:00" level=debug msg="new websocket client" Mar 30 22:50:24 volumio volumio[898]: info: Connection to go-librespot Websocket established Mar 30 22:50:24 volumio go-librespot[11200]: time="2024-03-30T22:50:24+08:00" level=debug msg="obtained new client token: AADV5Blo8j/1QAKa7xPgLB9nhi5u6I+YB++dPLCV6iXDN4WYqtJMudwas9OMc7b2GaN+PWduwxn27Yg3x8S7He+VeuEysvRKU1jjZR7cJ/RQ+Kg5xmhy7fSp3Zcg9V+lKx6NsHNAKYq0jAhVyOwhAzKdCICb9AFnMkoEezICZyibl4hGqxqrvY1+gq43yWjd51GsjNfbRFvCYlSbByUnlIpLDqk2VIAvhBQF/dMfKYZxTDyK9QO3XL6RDx/+H21C" Mar 30 22:50:25 volumio go-librespot[11200]: time="2024-03-30T22:50:25+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 30 22:50:25 volumio go-librespot[11200]: time="2024-03-30T22:50:25+08:00" level=debug msg="completed keyexchange" Mar 30 22:50:26 volumio go-librespot[11200]: time="2024-03-30T22:50:26+08:00" level=debug msg="completed challenge" Mar 30 22:50:26 volumio go-librespot[11200]: time="2024-03-30T22:50:26+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 30 22:50:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 30 22:50:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 30 22:50:26 volumio volumio[898]: info: Connection to go-librespot Websocket closed Mar 30 22:50:27 volumio volumio[898]: info: Getting Spotify volume Mar 30 22:50:27 volumio volumio[898]: (node:898) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 30 22:50:27 volumio volumio[898]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 30 22:50:27 volumio volumio[898]: (node:898) 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: 115) Mar 30 22:50:27 volumio volumio[898]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Mar 30 22:50:27 volumio volumio[898]: info: CoreCommandRouter::volumioGetState Mar 30 22:50:27 volumio volumio[898]: info: CorePlayQueue::getTrack 234 Mar 30 22:50:27 volumio volumio[898]: SPOTIFY: RECEIVED VOLUMIO VOLUME 97 Mar 30 22:50:28 volumio kernel: usb 1-1.4.3: USB disconnect, device number 22 Mar 30 22:50:29 volumio volumio[898]: info: No valid Plugin REST Endpoint Mar 30 22:50:29 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Mar 30 22:50:29 volumio volumio[898]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 30 22:50:29 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 30 22:50:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 215. Mar 30 22:50:29 volumio systemd[1]: Stopped go-librespot Daemon. Mar 30 22:50:29 volumio systemd[1]: Started go-librespot Daemon. Mar 30 22:50:29 volumio go-librespot[11223]: Librespot-go daemon starting... Mar 30 22:50:29 volumio go-librespot[11223]: time="2024-03-30T22:50:29+08:00" level=info msg="generated new device id: 7145f99cbdcbcf3d50bde72e0a196032c518968e" Mar 30 22:50:29 volumio go-librespot[11223]: time="2024-03-30T22:50:29+08:00" level=debug msg="stored credentials not found" Mar 30 22:50:29 volumio kernel: usb 1-1.4.3: new full-speed USB device number 23 using xhci_hcd Mar 30 22:50:29 volumio kernel: usb 1-1.4.3: New USB device found, idVendor=8087, idProduct=1024, bcdDevice= 1.00 Mar 30 22:50:29 volumio kernel: usb 1-1.4.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Mar 30 22:50:29 volumio kernel: usb 1-1.4.3: Product: USB PnP Audio Device Mar 30 22:50:29 volumio kernel: usb 1-1.4.3: Manufacturer: BlueTrm Mar 30 22:50:29 volumio kernel: usb 1-1.4.3: SerialNumber: 20170726905923 Mar 30 22:50:29 volumio kernel: usb 1-1.4.3: 5:0: bogus dB values (-12800/-12700), disabling dB reporting Mar 30 22:50:29 volumio volumio[898]: info: No valid Plugin REST Endpoint Mar 30 22:50:29 volumio go-librespot[11223]: time="2024-03-30T22:50:29+08:00" level=debug msg="obtained new client token: AAAKySM8LmDlciozpsBgcmTnJU9uCdESHu3gJH5ZS4Yz+eRO68Sceiud50xSpaNuMurcZhc/cS2I8blZZQkxIwPieqdhEkSOfogL4DjwUZpizvT0VXisXMlq1sjq99KMu44Yvq09Ol+HO62r1FmsKHXnZFn6JFQ8tjuQb7OkKji+0ABn8kkPDjC3RLer4TsuaKmx0ueGyXWRm6JCh1q9sngJE78wuS8kG1qf+Ue3Yb+oaYte0q43VI8asN2xvrYZ" Mar 30 22:50:30 volumio go-librespot[11223]: time="2024-03-30T22:50:30+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 30 22:50:30 volumio go-librespot[11223]: time="2024-03-30T22:50:30+08:00" level=debug msg="completed keyexchange" Mar 30 22:50:31 volumio go-librespot[11223]: time="2024-03-30T22:50:31+08:00" level=debug msg="completed challenge" Mar 30 22:50:31 volumio go-librespot[11223]: time="2024-03-30T22:50:31+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 30 22:50:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 30 22:50:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 30 22:50:32 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Mar 30 22:50:32 volumio volumio[898]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 30 22:50:34 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 30 22:50:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 216. Mar 30 22:50:34 volumio systemd[1]: Stopped go-librespot Daemon. Mar 30 22:50:34 volumio systemd[1]: Started go-librespot Daemon. Mar 30 22:50:34 volumio go-librespot[11244]: Librespot-go daemon starting... Mar 30 22:50:34 volumio go-librespot[11244]: time="2024-03-30T22:50:34+08:00" level=info msg="generated new device id: c799d1b819433a3a7866bddc73d9dd07048ec870" Mar 30 22:50:34 volumio go-librespot[11244]: time="2024-03-30T22:50:34+08:00" level=debug msg="stored credentials not found" Mar 30 22:50:34 volumio kernel: usb 1-1.4.3: USB disconnect, device number 23 Mar 30 22:50:34 volumio volumio[898]: info: No valid Plugin REST Endpoint Mar 30 22:50:35 volumio kernel: usb 1-1.4.3: new full-speed USB device number 24 using xhci_hcd Mar 30 22:50:35 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Mar 30 22:50:35 volumio volumio[898]: info: Connection to go-librespot Websocket established Mar 30 22:50:35 volumio go-librespot[11244]: time="2024-03-30T22:50:35+08:00" level=debug msg="new websocket client" Mar 30 22:50:35 volumio go-librespot[11244]: time="2024-03-30T22:50:35+08:00" level=debug msg="obtained new client token: AABHmQ0WzNVv/mHjvcWmfSKNHdI097+T2O74z2q17yMoue9gi1inZwo5/ZCLDM9FAO+UHpGyp6dh7JPbO3wrV2AwTbyN6c8zFClbjuAcYsalAQgzWuqRKh8sFFT98R+daGeuFWL+A2XwX6ouM9YG/Ap3C+b/HYmv03LmyUkT4G+aFPDR85N4vgaI8B82ofSRoebMlo4rbOigKXg+OsqQ8FrtsrXU/Y2Y52Z9HymSK0mUwUR5zpEEnXIJPyLihQ==" Mar 30 22:50:35 volumio kernel: usb 1-1.4.3: New USB device found, idVendor=8087, idProduct=1024, bcdDevice= 1.00 Mar 30 22:50:35 volumio kernel: usb 1-1.4.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Mar 30 22:50:35 volumio kernel: usb 1-1.4.3: Product: USB PnP Audio Device Mar 30 22:50:35 volumio kernel: usb 1-1.4.3: Manufacturer: BlueTrm Mar 30 22:50:35 volumio kernel: usb 1-1.4.3: SerialNumber: 20170726905923 Mar 30 22:50:35 volumio kernel: usb 1-1.4.3: 5:0: bogus dB values (-12800/-12700), disabling dB reporting Mar 30 22:50:35 volumio volumio[898]: info: No valid Plugin REST Endpoint Mar 30 22:50:36 volumio go-librespot[11244]: time="2024-03-30T22:50:36+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-gew1.spotify.com:80]" Mar 30 22:50:36 volumio go-librespot[11244]: time="2024-03-30T22:50:36+08:00" level=debug msg="completed keyexchange" Mar 30 22:50:37 volumio go-librespot[11244]: time="2024-03-30T22:50:37+08:00" level=debug msg="completed challenge" Mar 30 22:50:37 volumio go-librespot[11244]: time="2024-03-30T22:50:37+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 30 22:50:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 30 22:50:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 30 22:50:37 volumio volumio[898]: info: Connection to go-librespot Websocket closed Mar 30 22:50:38 volumio volumio[898]: info: Getting Spotify volume Mar 30 22:50:38 volumio volumio[898]: (node:898) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 30 22:50:38 volumio volumio[898]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 30 22:50:38 volumio volumio[898]: (node:898) 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: 116) Mar 30 22:50:38 volumio volumio[898]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Mar 30 22:50:38 volumio volumio[898]: info: CoreCommandRouter::volumioGetState Mar 30 22:50:38 volumio volumio[898]: info: CorePlayQueue::getTrack 234 Mar 30 22:50:38 volumio volumio[898]: SPOTIFY: RECEIVED VOLUMIO VOLUME 97 Mar 30 22:50:40 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Mar 30 22:50:40 volumio volumio[898]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 30 22:50:40 volumio kernel: usb 1-1.4.3: USB disconnect, device number 24 Mar 30 22:50:40 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 30 22:50:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 217. Mar 30 22:50:40 volumio systemd[1]: Stopped go-librespot Daemon. Mar 30 22:50:40 volumio volumio[898]: info: No valid Plugin REST Endpoint Mar 30 22:50:40 volumio systemd[1]: Started go-librespot Daemon. Mar 30 22:50:40 volumio go-librespot[11330]: Librespot-go daemon starting... Mar 30 22:50:40 volumio go-librespot[11330]: time="2024-03-30T22:50:40+08:00" level=info msg="generated new device id: 34929c97a4f5ea6b953a6e1a2c4c57d48f6d4daf" Mar 30 22:50:40 volumio go-librespot[11330]: time="2024-03-30T22:50:40+08:00" level=debug msg="stored credentials not found" Mar 30 22:50:40 volumio kernel: usb 1-1.4.3: new full-speed USB device number 25 using xhci_hcd Mar 30 22:50:40 volumio kernel: usb 1-1.4.3: New USB device found, idVendor=8087, idProduct=1024, bcdDevice= 1.00 Mar 30 22:50:40 volumio kernel: usb 1-1.4.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Mar 30 22:50:40 volumio kernel: usb 1-1.4.3: Product: USB PnP Audio Device Mar 30 22:50:40 volumio kernel: usb 1-1.4.3: Manufacturer: BlueTrm Mar 30 22:50:40 volumio kernel: usb 1-1.4.3: SerialNumber: 20170726905923 Mar 30 22:50:40 volumio kernel: usb 1-1.4.3: 5:0: bogus dB values (-12800/-12700), disabling dB reporting Mar 30 22:50:40 volumio volumio[898]: info: No valid Plugin REST Endpoint Mar 30 22:50:41 volumio go-librespot[11330]: time="2024-03-30T22:50:41+08:00" level=debug msg="obtained new client token: AACBK2xJAQSWpmFklJfhLQKu1CID+0R2HBYc+QNMTtFJoua+Hutm0CUz30pMJM2ZdMvkRm7A5OqrSU7sco/eMm+0vnW+Rtfxq8iu3pAlAdGOdM6m3wNrvDtaydOXxTe28G7uS8oooxrAg4EkqO2JEb8fad9nXmK6qbK9V4Ey+cg4NCoV3Klrq84V4TVpj7O0z+g4IMVnZz7Qe4a5+0JQIXYH6l/OwkHryDjNN4NDBWrnnp3xrkYlmm3dz7kyu5TM" Mar 30 22:50:43 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Mar 30 22:50:43 volumio go-librespot[11330]: time="2024-03-30T22:50:43+08:00" level=debug msg="new websocket client" Mar 30 22:50:43 volumio volumio[898]: info: Connection to go-librespot Websocket established Mar 30 22:50:43 volumio go-librespot[11330]: time="2024-03-30T22:50:43+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 30 22:50:43 volumio go-librespot[11330]: time="2024-03-30T22:50:43+08:00" level=debug msg="completed keyexchange" Mar 30 22:50:44 volumio go-librespot[11330]: time="2024-03-30T22:50:44+08:00" level=debug msg="completed challenge" Mar 30 22:50:44 volumio go-librespot[11330]: time="2024-03-30T22:50: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 30 22:50:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 30 22:50:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 30 22:50:44 volumio volumio[898]: info: Connection to go-librespot Websocket closed Mar 30 22:50:45 volumio kernel: usb 1-1.4.3: USB disconnect, device number 25 Mar 30 22:50:45 volumio volumio[898]: info: No valid Plugin REST Endpoint Mar 30 22:50:46 volumio volumio[898]: info: Getting Spotify volume Mar 30 22:50:46 volumio volumio[898]: (node:898) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 30 22:50:46 volumio volumio[898]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 30 22:50:46 volumio volumio[898]: (node:898) 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: 117) Mar 30 22:50:46 volumio volumio[898]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Mar 30 22:50:46 volumio volumio[898]: info: CoreCommandRouter::volumioGetState Mar 30 22:50:46 volumio volumio[898]: info: CorePlayQueue::getTrack 234 Mar 30 22:50:46 volumio volumio[898]: SPOTIFY: RECEIVED VOLUMIO VOLUME 97 Mar 30 22:50:46 volumio kernel: usb 1-1.4.3: new full-speed USB device number 26 using xhci_hcd Mar 30 22:50:46 volumio kernel: usb 1-1.4.3: New USB device found, idVendor=8087, idProduct=1024, bcdDevice= 1.00 Mar 30 22:50:46 volumio kernel: usb 1-1.4.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Mar 30 22:50:46 volumio kernel: usb 1-1.4.3: Product: USB PnP Audio Device Mar 30 22:50:46 volumio kernel: usb 1-1.4.3: Manufacturer: BlueTrm Mar 30 22:50:46 volumio kernel: usb 1-1.4.3: SerialNumber: 20170726905923 Mar 30 22:50:46 volumio kernel: usb 1-1.4.3: 5:0: bogus dB values (-12800/-12700), disabling dB reporting Mar 30 22:50:46 volumio volumio[898]: info: No valid Plugin REST Endpoint Mar 30 22:50:47 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Mar 30 22:50:47 volumio volumio[898]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 30 22:50:47 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 30 22:50:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 218. Mar 30 22:50:47 volumio systemd[1]: Stopped go-librespot Daemon. Mar 30 22:50:47 volumio systemd[1]: Started go-librespot Daemon. Mar 30 22:50:47 volumio go-librespot[11365]: Librespot-go daemon starting... Mar 30 22:50:47 volumio go-librespot[11365]: time="2024-03-30T22:50:47+08:00" level=info msg="generated new device id: 24d31cac5a4d7d759233542c49f6e537ae13a526" Mar 30 22:50:47 volumio go-librespot[11365]: time="2024-03-30T22:50:47+08:00" level=debug msg="stored credentials not found" Mar 30 22:50:48 volumio go-librespot[11365]: time="2024-03-30T22:50:48+08:00" level=debug msg="obtained new client token: AACqN6INLiLzlp/oYqyjYB+ssFSDpD+5CT6cGAMLZEsscp15ajPBP5tferoehk2JuzH4LYWhs9lt7/keuM2mFk8TLvkterWF6SWUlfeup2pWvonvHUol+1aDOXUvqze3Zti/hjQ8spu22DxbDT0tLmriwOxPwiL43epFqEe4E7nSMFmw+8zmKOvmZWXJNBbDzncC+No79tvbSMX140nCQeyMkYU+a8G3c4jWbpGLpQE2SkIQ3GCVM5vkjc+ocMxL" Mar 30 22:50:48 volumio go-librespot[11365]: time="2024-03-30T22:50:48+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 30 22:50:50 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Mar 30 22:50:50 volumio go-librespot[11365]: time="2024-03-30T22:50:50+08:00" level=debug msg="new websocket client" Mar 30 22:50:50 volumio volumio[898]: info: Connection to go-librespot Websocket established Mar 30 22:50:50 volumio go-librespot[11365]: time="2024-03-30T22:50:50+08:00" level=debug msg="completed keyexchange" Mar 30 22:50:51 volumio go-librespot[11365]: time="2024-03-30T22:50:51+08:00" level=debug msg="completed challenge" Mar 30 22:50:51 volumio go-librespot[11365]: time="2024-03-30T22:50:51+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 30 22:50:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 30 22:50:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 30 22:50:51 volumio volumio[898]: info: Connection to go-librespot Websocket closed Mar 30 22:50:51 volumio kernel: usb 1-1.4.3: USB disconnect, device number 26 Mar 30 22:50:51 volumio volumio[898]: info: No valid Plugin REST Endpoint Mar 30 22:50:51 volumio kernel: usb 1-1.4.3: new full-speed USB device number 27 using xhci_hcd Mar 30 22:50:52 volumio kernel: usb 1-1.4.3: New USB device found, idVendor=8087, idProduct=1024, bcdDevice= 1.00 Mar 30 22:50:52 volumio kernel: usb 1-1.4.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Mar 30 22:50:52 volumio kernel: usb 1-1.4.3: Product: USB PnP Audio Device Mar 30 22:50:52 volumio kernel: usb 1-1.4.3: Manufacturer: BlueTrm Mar 30 22:50:52 volumio kernel: usb 1-1.4.3: SerialNumber: 20170726905923 Mar 30 22:50:52 volumio kernel: usb 1-1.4.3: 5:0: bogus dB values (-12800/-12700), disabling dB reporting Mar 30 22:50:52 volumio volumio[898]: info: No valid Plugin REST Endpoint Mar 30 22:50:53 volumio volumio[898]: info: Getting Spotify volume Mar 30 22:50:53 volumio volumio[898]: (node:898) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 30 22:50:53 volumio volumio[898]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 30 22:50:53 volumio volumio[898]: (node:898) 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: 118) Mar 30 22:50:53 volumio volumio[898]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Mar 30 22:50:53 volumio volumio[898]: info: CoreCommandRouter::volumioGetState Mar 30 22:50:53 volumio volumio[898]: info: CorePlayQueue::getTrack 234 Mar 30 22:50:53 volumio volumio[898]: SPOTIFY: RECEIVED VOLUMIO VOLUME 97 Mar 30 22:50:54 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Mar 30 22:50:54 volumio volumio[898]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 30 22:50:54 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 30 22:50:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 219. Mar 30 22:50:54 volumio systemd[1]: Stopped go-librespot Daemon. Mar 30 22:50:54 volumio systemd[1]: Started go-librespot Daemon. Mar 30 22:50:54 volumio go-librespot[11398]: Librespot-go daemon starting... Mar 30 22:50:54 volumio go-librespot[11398]: time="2024-03-30T22:50:54+08:00" level=info msg="generated new device id: 3d2feb24ef06a83ec217409aae6d0b7ef37693b4" Mar 30 22:50:54 volumio go-librespot[11398]: time="2024-03-30T22:50:54+08:00" level=debug msg="stored credentials not found" Mar 30 22:50:55 volumio go-librespot[11398]: time="2024-03-30T22:50:55+08:00" level=debug msg="obtained new client token: AAAsrcOrfQnsITD3XpD8MoF/go4/AdPKmMAZEZ3/Y9DU8gwi7HdYtjTIWEgijGuL3QQCW+dSK0uTe72njatv7rycZSDoBLzJSa+FNTVE6SGHmBZ8vctGn01+DhUxOOu2PfZgmneSCEeQSUefuojHoJZJr8Cs1LSpjFpFvdzVRzdfmv6HJHQlS/N9xIRCmKrjplw4gLjDOIj/ve4srObRcg8kQc83daaoFMuZoQNDCtYNURqoWNtH255GuQM48Q==" Mar 30 22:50:56 volumio go-librespot[11398]: time="2024-03-30T22:50:56+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 30 22:50:56 volumio go-librespot[11398]: time="2024-03-30T22:50:56+08:00" level=debug msg="completed keyexchange" Mar 30 22:50:56 volumio go-librespot[11398]: time="2024-03-30T22:50:56+08:00" level=debug msg="completed challenge" Mar 30 22:50:56 volumio go-librespot[11398]: time="2024-03-30T22:50:56+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 30 22:50:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 30 22:50:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 30 22:50:57 volumio kernel: usb 1-1.4.3: USB disconnect, device number 27 Mar 30 22:50:57 volumio volumio[898]: info: No valid Plugin REST Endpoint Mar 30 22:50:57 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Mar 30 22:50:57 volumio volumio[898]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 30 22:50:57 volumio kernel: usb 1-1.4.3: new full-speed USB device number 28 using xhci_hcd Mar 30 22:50:57 volumio kernel: usb 1-1.4.3: New USB device found, idVendor=8087, idProduct=1024, bcdDevice= 1.00 Mar 30 22:50:57 volumio kernel: usb 1-1.4.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Mar 30 22:50:57 volumio kernel: usb 1-1.4.3: Product: USB PnP Audio Device Mar 30 22:50:57 volumio kernel: usb 1-1.4.3: Manufacturer: BlueTrm Mar 30 22:50:57 volumio kernel: usb 1-1.4.3: SerialNumber: 20170726905923 Mar 30 22:50:57 volumio kernel: usb 1-1.4.3: 5:0: bogus dB values (-12800/-12700), disabling dB reporting Mar 30 22:50:57 volumio volumio[898]: info: No valid Plugin REST Endpoint Mar 30 22:51:00 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 30 22:51:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 220. Mar 30 22:51:00 volumio systemd[1]: Stopped go-librespot Daemon. Mar 30 22:51:00 volumio systemd[1]: Started go-librespot Daemon. Mar 30 22:51:00 volumio go-librespot[11423]: Librespot-go daemon starting... Mar 30 22:51:00 volumio go-librespot[11423]: time="2024-03-30T22:51:00+08:00" level=info msg="generated new device id: b24fe7163ceccacc9987bfd019770412321af7fa" Mar 30 22:51:00 volumio go-librespot[11423]: time="2024-03-30T22:51:00+08:00" level=debug msg="stored credentials not found" Mar 30 22:51:00 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Mar 30 22:51:00 volumio go-librespot[11423]: time="2024-03-30T22:51:00+08:00" level=debug msg="new websocket client" Mar 30 22:51:00 volumio volumio[898]: info: Connection to go-librespot Websocket established Mar 30 22:51:00 volumio go-librespot[11423]: time="2024-03-30T22:51:00+08:00" level=debug msg="obtained new client token: AAADy/sRQ7X4tGRWSSPL0+LiWAiBVsE8BjWTg9OcvnY8gLUwEVZpQlLGJu0afnj1ZuCHbpBqrJr4WlwpWsJY9+gBHSveiPdifEepJPkijgQCfuitQB9pFwe3pYHVS4eA7zF7KTIcKzBkzEETz0EbhGIrpyck2jzOmGydvXfOBg8u9FxKXucd4S2Xe2PpMGmmrWLK1Yibr0ieUQJTgaHaPxYwbE90wu3WbsXslCX4xzoe8EGh2IVncgvFO4zScHIx" Mar 30 22:51:01 volumio go-librespot[11423]: time="2024-03-30T22:51:01+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 30 22:51:01 volumio go-librespot[11423]: time="2024-03-30T22:51:01+08:00" level=debug msg="completed keyexchange" Mar 30 22:51:02 volumio go-librespot[11423]: time="2024-03-30T22:51:02+08:00" level=debug msg="completed challenge" Mar 30 22:51:02 volumio go-librespot[11423]: time="2024-03-30T22:51:02+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 30 22:51:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 30 22:51:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 30 22:51:02 volumio volumio[898]: info: Connection to go-librespot Websocket closed Mar 30 22:51:02 volumio kernel: usb 1-1.4.3: USB disconnect, device number 28 Mar 30 22:51:02 volumio volumio[898]: info: No valid Plugin REST Endpoint Mar 30 22:51:03 volumio kernel: usb 1-1.4.3: new full-speed USB device number 29 using xhci_hcd Mar 30 22:51:03 volumio volumio[898]: info: Getting Spotify volume Mar 30 22:51:03 volumio kernel: usb 1-1.4.3: New USB device found, idVendor=8087, idProduct=1024, bcdDevice= 1.00 Mar 30 22:51:03 volumio kernel: usb 1-1.4.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Mar 30 22:51:03 volumio kernel: usb 1-1.4.3: Product: USB PnP Audio Device Mar 30 22:51:03 volumio kernel: usb 1-1.4.3: Manufacturer: BlueTrm Mar 30 22:51:03 volumio kernel: usb 1-1.4.3: SerialNumber: 20170726905923 Mar 30 22:51:03 volumio volumio[898]: (node:898) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 30 22:51:03 volumio volumio[898]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 30 22:51:03 volumio volumio[898]: (node:898) 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: 119) Mar 30 22:51:03 volumio volumio[898]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Mar 30 22:51:03 volumio kernel: usb 1-1.4.3: 5:0: bogus dB values (-12800/-12700), disabling dB reporting Mar 30 22:51:03 volumio volumio[898]: info: CoreCommandRouter::volumioGetState Mar 30 22:51:03 volumio volumio[898]: info: CorePlayQueue::getTrack 234 Mar 30 22:51:03 volumio volumio[898]: SPOTIFY: RECEIVED VOLUMIO VOLUME 97 Mar 30 22:51:03 volumio volumio[898]: info: No valid Plugin REST Endpoint Mar 30 22:51:05 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Mar 30 22:51:05 volumio volumio[898]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 30 22:51:05 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 30 22:51:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 221. Mar 30 22:51:05 volumio systemd[1]: Stopped go-librespot Daemon. Mar 30 22:51:05 volumio systemd[1]: Started go-librespot Daemon. Mar 30 22:51:05 volumio go-librespot[11448]: Librespot-go daemon starting... Mar 30 22:51:05 volumio go-librespot[11448]: time="2024-03-30T22:51:05+08:00" level=info msg="generated new device id: f1d20019ca274ff164c340912d00e34cb3bebf2f" Mar 30 22:51:05 volumio go-librespot[11448]: time="2024-03-30T22:51:05+08:00" level=debug msg="stored credentials not found" Mar 30 22:51:05 volumio go-librespot[11448]: time="2024-03-30T22:51:05+08:00" level=debug msg="obtained new client token: AABrmoUSNNl07Z8nfs6K7aNwcrsl+KUwe8MDsi5JPiHVGEW+xXRPj/KVfg9jtBZSws+q8BZr14H9qJ0Rukyk3rgtbIXfSCuW31tBh0leBBTQJ+g1icmd0ZDeHlC8Mkf6fxTsoqbyMiS0ExzqQ11zAYaeIQV9c0rDTOIQNJrhbG+s4YCV68mox1J0RDsmniMF5nMAoprsuT4+zUsQMqcG83MoKDtDmyvtWzwCslD5k6MrXWUcVe+YqQ4wbFgdLvQj" Mar 30 22:51:06 volumio go-librespot[11448]: time="2024-03-30T22:51:06+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 30 22:51:07 volumio go-librespot[11448]: time="2024-03-30T22:51:07+08:00" level=debug msg="completed keyexchange" Mar 30 22:51:07 volumio go-librespot[11448]: time="2024-03-30T22:51:07+08:00" level=debug msg="completed challenge" Mar 30 22:51:07 volumio go-librespot[11448]: time="2024-03-30T22:51:07+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 30 22:51:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 30 22:51:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 30 22:51:08 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Mar 30 22:51:08 volumio volumio[898]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 30 22:51:08 volumio kernel: usb 1-1.4.3: USB disconnect, device number 29 Mar 30 22:51:08 volumio volumio[898]: info: No valid Plugin REST Endpoint Mar 30 22:51:08 volumio kernel: usb 1-1.4.3: new full-speed USB device number 30 using xhci_hcd Mar 30 22:51:09 volumio kernel: usb 1-1.4.3: New USB device found, idVendor=8087, idProduct=1024, bcdDevice= 1.00 Mar 30 22:51:09 volumio kernel: usb 1-1.4.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Mar 30 22:51:09 volumio kernel: usb 1-1.4.3: Product: USB PnP Audio Device Mar 30 22:51:09 volumio kernel: usb 1-1.4.3: Manufacturer: BlueTrm Mar 30 22:51:09 volumio kernel: usb 1-1.4.3: SerialNumber: 20170726905923 Mar 30 22:51:09 volumio kernel: usb 1-1.4.3: 5:0: bogus dB values (-12800/-12700), disabling dB reporting Mar 30 22:51:09 volumio volumio[898]: info: No valid Plugin REST Endpoint Mar 30 22:51:10 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 30 22:51:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 222. Mar 30 22:51:10 volumio systemd[1]: Stopped go-librespot Daemon. Mar 30 22:51:10 volumio systemd[1]: Started go-librespot Daemon. Mar 30 22:51:10 volumio go-librespot[11476]: Librespot-go daemon starting... Mar 30 22:51:10 volumio go-librespot[11476]: time="2024-03-30T22:51:10+08:00" level=info msg="generated new device id: def0dc04d07892d1fe4c7dbdd485682f424890dd" Mar 30 22:51:10 volumio go-librespot[11476]: time="2024-03-30T22:51:10+08:00" level=debug msg="stored credentials not found" Mar 30 22:51:11 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Mar 30 22:51:11 volumio volumio[898]: info: Connection to go-librespot Websocket established Mar 30 22:51:11 volumio go-librespot[11476]: time="2024-03-30T22:51:11+08:00" level=debug msg="new websocket client" Mar 30 22:51:11 volumio go-librespot[11476]: time="2024-03-30T22:51:11+08:00" level=debug msg="obtained new client token: AAAra4KR8M2cmjPHWl+SSpFv4YM1h8sp44suK1noqqD06b1RaKlNQqTAsYf/lKsuKZvBjY8igGZ4LKPmpM4wBKqAXyEuaL6HH2Zb8lB6FqLWiEt8m9J3u+90k3xtZAsQTRQYZpSh6ROwajcCbN48jsLueRewVsWeJlth/9mU/2mJ5DLFF6/ZZk/zT3XpIAixO2kiEuGAAueUzuV1p5cC0BeOHo5Yjq7ysbe/z0kcZDekDHZhkfqghw2vhZKcxxgo" Mar 30 22:51:12 volumio go-librespot[11476]: time="2024-03-30T22:51:12+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 30 22:51:12 volumio go-librespot[11476]: time="2024-03-30T22:51:12+08:00" level=debug msg="completed keyexchange" Mar 30 22:51:13 volumio go-librespot[11476]: time="2024-03-30T22:51:13+08:00" level=debug msg="completed challenge" Mar 30 22:51:13 volumio go-librespot[11476]: time="2024-03-30T22:51:13+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 30 22:51:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 30 22:51:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 30 22:51:13 volumio volumio[898]: info: Connection to go-librespot Websocket closed Mar 30 22:51:14 volumio kernel: usb 1-1.4.3: USB disconnect, device number 30 Mar 30 22:51:14 volumio volumio[898]: info: No valid Plugin REST Endpoint Mar 30 22:51:14 volumio volumio[898]: info: Getting Spotify volume Mar 30 22:51:14 volumio volumio[898]: (node:898) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 30 22:51:14 volumio volumio[898]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 30 22:51:14 volumio volumio[898]: (node:898) 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: 120) Mar 30 22:51:14 volumio volumio[898]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Mar 30 22:51:14 volumio volumio[898]: info: CoreCommandRouter::volumioGetState Mar 30 22:51:14 volumio volumio[898]: info: CorePlayQueue::getTrack 234 Mar 30 22:51:14 volumio volumio[898]: SPOTIFY: RECEIVED VOLUMIO VOLUME 97 Mar 30 22:51:14 volumio kernel: usb 1-1.4.3: new full-speed USB device number 31 using xhci_hcd Mar 30 22:51:14 volumio kernel: usb 1-1.4.3: New USB device found, idVendor=8087, idProduct=1024, bcdDevice= 1.00 Mar 30 22:51:14 volumio kernel: usb 1-1.4.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Mar 30 22:51:14 volumio kernel: usb 1-1.4.3: Product: USB PnP Audio Device Mar 30 22:51:14 volumio kernel: usb 1-1.4.3: Manufacturer: BlueTrm Mar 30 22:51:14 volumio kernel: usb 1-1.4.3: SerialNumber: 20170726905923 Mar 30 22:51:14 volumio kernel: usb 1-1.4.3: 5:0: bogus dB values (-12800/-12700), disabling dB reporting Mar 30 22:51:14 volumio volumio[898]: info: No valid Plugin REST Endpoint Mar 30 22:51:16 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Mar 30 22:51:16 volumio volumio[898]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 30 22:51:16 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 30 22:51:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 223. Mar 30 22:51:16 volumio systemd[1]: Stopped go-librespot Daemon. Mar 30 22:51:16 volumio systemd[1]: Started go-librespot Daemon. Mar 30 22:51:16 volumio go-librespot[11502]: Librespot-go daemon starting... Mar 30 22:51:16 volumio go-librespot[11502]: time="2024-03-30T22:51:16+08:00" level=info msg="generated new device id: 7fd16772f548dfb3115314c8f7678755e0e9e38e" Mar 30 22:51:16 volumio go-librespot[11502]: time="2024-03-30T22:51:16+08:00" level=debug msg="stored credentials not found" Mar 30 22:51:17 volumio go-librespot[11502]: time="2024-03-30T22:51:17+08:00" level=debug msg="obtained new client token: AACYoVLf8e/SXmAO4bVkbroieKhfELNuJEWs4oEGOgVshZVAfMZz0IA+xOvhgPc5gxkJv/c4cZ5lnJ9ZEj4c+VyRA3PW4ML/jl8Qx0hDzA4q5RlWDgLkH1SNIxjbxTA+iqPew5lCK7UFZuLRpaXFSofjtqfiNLjWp6BXDuZwuiMgkS2gH6iMHSGa0xJ2e7NhkIiNczx99adVNjnCexzHw0GCWP4cNNKubXZv/u7jBAvMair+PtGVFw/Y2EKuRNCk" Mar 30 22:51:18 volumio go-librespot[11502]: time="2024-03-30T22:51: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 30 22:51:18 volumio go-librespot[11502]: time="2024-03-30T22:51:18+08:00" level=debug msg="completed keyexchange" Mar 30 22:51:18 volumio go-librespot[11502]: time="2024-03-30T22:51:18+08:00" level=debug msg="completed challenge" Mar 30 22:51:18 volumio go-librespot[11502]: time="2024-03-30T22:51:18+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 30 22:51:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 30 22:51:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 30 22:51:19 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Mar 30 22:51:19 volumio volumio[898]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 30 22:51:19 volumio kernel: usb 1-1.4.3: USB disconnect, device number 31 Mar 30 22:51:19 volumio volumio[898]: info: No valid Plugin REST Endpoint Mar 30 22:51:20 volumio kernel: usb 1-1.4.3: new full-speed USB device number 32 using xhci_hcd Mar 30 22:51:20 volumio kernel: usb 1-1.4.3: New USB device found, idVendor=8087, idProduct=1024, bcdDevice= 1.00 Mar 30 22:51:20 volumio kernel: usb 1-1.4.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Mar 30 22:51:20 volumio kernel: usb 1-1.4.3: Product: USB PnP Audio Device Mar 30 22:51:20 volumio kernel: usb 1-1.4.3: Manufacturer: BlueTrm Mar 30 22:51:20 volumio kernel: usb 1-1.4.3: SerialNumber: 20170726905923 Mar 30 22:51:20 volumio kernel: usb 1-1.4.3: 5:0: bogus dB values (-12800/-12700), disabling dB reporting Mar 30 22:51:20 volumio volumio[898]: info: No valid Plugin REST Endpoint Mar 30 22:51:22 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 30 22:51:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 224. Mar 30 22:51:22 volumio systemd[1]: Stopped go-librespot Daemon. Mar 30 22:51:22 volumio systemd[1]: Started go-librespot Daemon. Mar 30 22:51:22 volumio go-librespot[11531]: Librespot-go daemon starting... Mar 30 22:51:22 volumio go-librespot[11531]: time="2024-03-30T22:51:22+08:00" level=info msg="generated new device id: 886a4fb22c49d6c252c63eb94fe26611f6825f7a" Mar 30 22:51:22 volumio go-librespot[11531]: time="2024-03-30T22:51:22+08:00" level=debug msg="stored credentials not found" Mar 30 22:51:22 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Mar 30 22:51:22 volumio go-librespot[11531]: time="2024-03-30T22:51:22+08:00" level=debug msg="new websocket client" Mar 30 22:51:22 volumio volumio[898]: info: Connection to go-librespot Websocket established Mar 30 22:51:22 volumio go-librespot[11531]: time="2024-03-30T22:51:22+08:00" level=debug msg="obtained new client token: AACzLt9zHClGu/KsPdPCz05bdASHysq/3dOyet3a5bOLpx56IHp3xtzFcsSPZhJHD4oQbGoAZ6Il2ZXUcuuioMUQKR72hgjBQoLt/DcK9rHTqCsbBZRnpw9/nFsQNOO13hU8LvTr4maYdeoc/pJyZkzSeVKIfGJmyqqtXDts9DOFvk/vJl2gqDVGxwRJSsuiv1x5XMNsBDvVE5bx1PqTPaOJfDhyEjice/DVP2CpVHiXTJdWQaw/oiqGen5qfB7d" Mar 30 22:51:23 volumio go-librespot[11531]: time="2024-03-30T22:51:23+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-gew1.spotify.com:80]" Mar 30 22:51:23 volumio go-librespot[11531]: time="2024-03-30T22:51:23+08:00" level=debug msg="completed keyexchange" Mar 30 22:51:24 volumio go-librespot[11531]: time="2024-03-30T22:51:24+08:00" level=debug msg="completed challenge" Mar 30 22:51:24 volumio go-librespot[11531]: time="2024-03-30T22:51: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 30 22:51:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 30 22:51:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 30 22:51:24 volumio volumio[898]: info: Connection to go-librespot Websocket closed Mar 30 22:51:25 volumio kernel: usb 1-1.4.3: USB disconnect, device number 32 Mar 30 22:51:25 volumio volumio[898]: info: No valid Plugin REST Endpoint Mar 30 22:51:25 volumio volumio[898]: info: Getting Spotify volume Mar 30 22:51:25 volumio volumio[898]: (node:898) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 30 22:51:25 volumio volumio[898]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 30 22:51:25 volumio volumio[898]: (node:898) 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: 121) Mar 30 22:51:25 volumio volumio[898]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Mar 30 22:51:25 volumio volumio[898]: info: CoreCommandRouter::volumioGetState Mar 30 22:51:25 volumio volumio[898]: info: CorePlayQueue::getTrack 234 Mar 30 22:51:25 volumio volumio[898]: SPOTIFY: RECEIVED VOLUMIO VOLUME 97 Mar 30 22:51:25 volumio kernel: usb 1-1.4.3: new full-speed USB device number 33 using xhci_hcd Mar 30 22:51:25 volumio kernel: usb 1-1.4.3: New USB device found, idVendor=8087, idProduct=1024, bcdDevice= 1.00 Mar 30 22:51:25 volumio kernel: usb 1-1.4.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Mar 30 22:51:25 volumio kernel: usb 1-1.4.3: Product: USB PnP Audio Device Mar 30 22:51:25 volumio kernel: usb 1-1.4.3: Manufacturer: BlueTrm Mar 30 22:51:25 volumio kernel: usb 1-1.4.3: SerialNumber: 20170726905923 Mar 30 22:51:25 volumio kernel: usb 1-1.4.3: 5:0: bogus dB values (-12800/-12700), disabling dB reporting Mar 30 22:51:26 volumio volumio[898]: info: No valid Plugin REST Endpoint Mar 30 22:51:27 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Mar 30 22:51:27 volumio volumio[898]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 30 22:51:27 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 30 22:51:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 225. Mar 30 22:51:27 volumio systemd[1]: Stopped go-librespot Daemon. Mar 30 22:51:27 volumio systemd[1]: Started go-librespot Daemon. Mar 30 22:51:27 volumio go-librespot[11556]: Librespot-go daemon starting... Mar 30 22:51:27 volumio go-librespot[11556]: time="2024-03-30T22:51:27+08:00" level=info msg="generated new device id: 0ba444fdcc6f4ecfef9943bca2f7de15c074f975" Mar 30 22:51:27 volumio go-librespot[11556]: time="2024-03-30T22:51:27+08:00" level=debug msg="stored credentials not found" Mar 30 22:51:28 volumio go-librespot[11556]: time="2024-03-30T22:51:28+08:00" level=debug msg="obtained new client token: AAAlYOfFNwRW6kUrZUm8+SjadRQ8kfm0fSlzU+hQxelJdk7peJDVEvL+//CS22/vYLoigUpaALKHcwZk6rmx0KfgmjrNI9nyk0V0c5gnmnaXeWTIlZQ9WrVJ43nzle62627im3EpLjOiw0Uvxr0+vgyzTeUl+cWycSS9D2ufOhtlwbz8RG5fuOqL0uHojvK4FfqoIdsu6tCyB5yZ2ASlXrJlMl7byGeusq1u0JCyxsZLbzEagSrDYYExVUo9tMGB" Mar 30 22:51:29 volumio go-librespot[11556]: time="2024-03-30T22:51:29+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-gew1.spotify.com:80]" Mar 30 22:51:29 volumio volumio[898]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 30 22:51:29 volumio volumio[898]: Error: connect ETIMEDOUT 104.244.46.57:80 Mar 30 22:51:29 volumio volumio[898]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) { Mar 30 22:51:29 volumio volumio[898]: errno: -110, Mar 30 22:51:29 volumio volumio[898]: code: 'ETIMEDOUT', Mar 30 22:51:29 volumio volumio[898]: syscall: 'connect', Mar 30 22:51:29 volumio volumio[898]: address: '104.244.46.57', Mar 30 22:51:29 volumio volumio[898]: port: 80 Mar 30 22:51:29 volumio volumio[898]: } Mar 30 22:51:29 volumio volumio[898]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 30 22:51:30 volumio sudo[11578]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-03-30 22:50 Mar 30 22:51:30 volumio sudo[11578]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 30 22:51:30 volumio go-librespot[11556]: time="2024-03-30T22:51:30+08:00" level=debug msg="completed keyexchange" 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"