-- Logs begin at Fri 2024-03-29 17:14:57 MSK, end at Fri 2024-03-29 18:30:50 MSK. -- Mar 29 18:29:00 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:00 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:00 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:00 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:01 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:01 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:01 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:01 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:01 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 29 18:29:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4416. Mar 29 18:29:01 volumio systemd[1]: Stopped go-librespot Daemon. Mar 29 18:29:01 volumio systemd[1]: Started go-librespot Daemon. Mar 29 18:29:01 volumio go-librespot[18309]: Librespot-go daemon starting... Mar 29 18:29:01 volumio go-librespot[18309]: time="2024-03-29T18:29:01+03:00" level=info msg="generated new device id: 56cf718d4630e2f46998a21cb5313a670b0597a4" Mar 29 18:29:01 volumio go-librespot[18309]: time="2024-03-29T18:29:01+03:00" level=debug msg="stored credentials found for 31szglwegdhn6gw7vu4wo4rv33ya" Mar 29 18:29:01 volumio go-librespot[18309]: time="2024-03-29T18:29:01+03:00" level=debug msg="obtained new client token: AACUEO0lPjiOaY4fv5krZHnq13ZKNEYXMXBXHn//W7RtUCO65avurMVpv+HpFqnuyVzv27szpKW3VkumwGtDh5rAfbghKK5EiM2I0QC9xytoFARQc+cWHzdYkZL+RuKNVLLIrf9vgFemh8oRKbCBplV43g3Mvq3eXUcI8StnoVOY7qfBdjr1DeEFLsISfPJCCxD59zD+Wh7V4ACjRnT9UXoUXpPmmxC9J3BPEiS+6VTTZG8oE8ovqggv4mX/" Mar 29 18:29:01 volumio go-librespot[18309]: time="2024-03-29T18:29:01+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 29 18:29:01 volumio volumio[891]: info: Initializing connection to go-librespot Websocket Mar 29 18:29:01 volumio go-librespot[18309]: time="2024-03-29T18:29:01+03:00" level=debug msg="new websocket client" Mar 29 18:29:01 volumio volumio[891]: info: Connection to go-librespot Websocket established Mar 29 18:29:01 volumio go-librespot[18309]: time="2024-03-29T18:29:01+03:00" level=debug msg="completed keyexchange" Mar 29 18:29:02 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:02 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:02 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:02 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:02 volumio go-librespot[18309]: time="2024-03-29T18:29:02+03:00" level=debug msg="completed challenge" Mar 29 18:29:02 volumio go-librespot[18309]: time="2024-03-29T18:29:02+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 29 18:29:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 29 18:29:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 29 18:29:02 volumio volumio[891]: info: Connection to go-librespot Websocket closed Mar 29 18:29:02 volumio volumio[891]: info: CoreCommandRouter::volumioGetState Mar 29 18:29:02 volumio volumio[891]: info: CorePlayQueue::getTrack 0 Mar 29 18:29:03 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:03 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:03 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:03 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:04 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:04 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:04 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:04 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:04 volumio volumio[891]: info: Getting Spotify volume Mar 29 18:29:04 volumio volumio[891]: (node:891) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 18:29:04 volumio volumio[891]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 29 18:29:04 volumio volumio[891]: (node:891) 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: 1540) Mar 29 18:29:04 volumio volumio[891]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 6 Mar 29 18:29:04 volumio volumio[891]: info: CoreCommandRouter::volumioGetState Mar 29 18:29:04 volumio volumio[891]: info: CorePlayQueue::getTrack 0 Mar 29 18:29:05 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:05 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:05 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:05 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:05 volumio volumio[891]: info: Initializing connection to go-librespot Websocket Mar 29 18:29:05 volumio volumio[891]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 18:29:05 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 29 18:29:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4417. Mar 29 18:29:05 volumio systemd[1]: Stopped go-librespot Daemon. Mar 29 18:29:05 volumio systemd[1]: Started go-librespot Daemon. Mar 29 18:29:05 volumio go-librespot[18325]: Librespot-go daemon starting... Mar 29 18:29:05 volumio go-librespot[18325]: time="2024-03-29T18:29:05+03:00" level=info msg="generated new device id: 41fca564cb484ab558ed3dbff439fab97611a67e" Mar 29 18:29:05 volumio go-librespot[18325]: time="2024-03-29T18:29:05+03:00" level=debug msg="stored credentials found for 31szglwegdhn6gw7vu4wo4rv33ya" Mar 29 18:29:05 volumio go-librespot[18325]: time="2024-03-29T18:29:05+03:00" level=debug msg="obtained new client token: AABOSMQ5i/ZJ6h26Ohj/y2W+QQSI5jDu4tWK7o4DEhHCQkeqabzFOgbJ2W6u+xB508MIfjGd7qClALqNnkrSqwYmGUuPFqMfL/e3ZyzLBguld62HiZVyll6sCMaYMYO06uNx+DvrW1PlcNLFvmU6Q31ZLbWFUdgv+cERXJTyw+UeUS4uxVkIpQzoNEXfZ4DqB+NTxRQkIa/hN/GH0buC4nNgNA+NPQio6hPxoc3NG4EX76KIzpDGQvpuYLg6" Mar 29 18:29:05 volumio go-librespot[18325]: time="2024-03-29T18:29:05+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Mar 29 18:29:06 volumio go-librespot[18325]: time="2024-03-29T18:29:06+03:00" level=debug msg="completed keyexchange" Mar 29 18:29:06 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:06 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:06 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:06 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:06 volumio go-librespot[18325]: time="2024-03-29T18:29:06+03:00" level=debug msg="completed challenge" Mar 29 18:29:06 volumio go-librespot[18325]: time="2024-03-29T18:29:06+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 29 18:29:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 29 18:29:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 29 18:29:07 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:07 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:07 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:07 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:08 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:08 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:08 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:08 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:08 volumio volumio[891]: info: Initializing connection to go-librespot Websocket Mar 29 18:29:08 volumio volumio[891]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 18:29:09 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:09 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:09 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:09 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:09 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 29 18:29:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4418. Mar 29 18:29:09 volumio systemd[1]: Stopped go-librespot Daemon. Mar 29 18:29:09 volumio systemd[1]: Started go-librespot Daemon. Mar 29 18:29:09 volumio go-librespot[18381]: Librespot-go daemon starting... Mar 29 18:29:09 volumio go-librespot[18381]: time="2024-03-29T18:29:09+03:00" level=info msg="generated new device id: c0fe61a14691f3f4d19e4e4190ae3969b942114e" Mar 29 18:29:09 volumio go-librespot[18381]: time="2024-03-29T18:29:09+03:00" level=debug msg="stored credentials found for 31szglwegdhn6gw7vu4wo4rv33ya" Mar 29 18:29:10 volumio go-librespot[18381]: time="2024-03-29T18:29:10+03:00" level=debug msg="obtained new client token: AAAIycmB/l0KpXHlm8tmvxtlFsXkD5QON3ouateZTdnC8TliU5N3znl69pPl8h3B6AmUxoTmeLd4PtJIa+H3LX6l2xA7A6xmZeeMcHaqGtzDzylBkk0DBCxoeoHk7L3WoJesSHDiq6eIp1yy0pUze7xFy3odcJCOnsE+LHH6SLxdhWS+lHs8z3jHXqejdWkd9U1MVeo4Ls3c+YRv0T1C2Ta/JghsPMlS0IIfr04ZcEoDgCtTfCAKKXQ5nQ==" Mar 29 18:29:10 volumio go-librespot[18381]: time="2024-03-29T18:29:10+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 29 18:29:10 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:10 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:10 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:10 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:10 volumio go-librespot[18381]: time="2024-03-29T18:29:10+03:00" level=debug msg="completed keyexchange" Mar 29 18:29:10 volumio go-librespot[18381]: time="2024-03-29T18:29:10+03:00" level=debug msg="completed challenge" Mar 29 18:29:10 volumio go-librespot[18381]: time="2024-03-29T18:29:10+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 29 18:29:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 29 18:29:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 29 18:29:11 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:11 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:11 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:11 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:11 volumio volumio[891]: info: Initializing connection to go-librespot Websocket Mar 29 18:29:11 volumio volumio[891]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 18:29:12 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:12 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:12 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:12 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:12 volumio volumio[891]: info: CoreCommandRouter::volumioGetState Mar 29 18:29:12 volumio volumio[891]: info: CorePlayQueue::getTrack 0 Mar 29 18:29:12 volumio volumio[891]: info: Listing playlists Mar 29 18:29:12 volumio volumio[891]: info: Listing playlists Mar 29 18:29:13 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:13 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:13 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:13 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:14 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 29 18:29:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4419. Mar 29 18:29:14 volumio systemd[1]: Stopped go-librespot Daemon. Mar 29 18:29:14 volumio systemd[1]: Started go-librespot Daemon. Mar 29 18:29:14 volumio go-librespot[18397]: Librespot-go daemon starting... Mar 29 18:29:14 volumio go-librespot[18397]: time="2024-03-29T18:29:14+03:00" level=info msg="generated new device id: b3f53977e51e8fcc46611e30904f271170e25f20" Mar 29 18:29:14 volumio go-librespot[18397]: time="2024-03-29T18:29:14+03:00" level=debug msg="stored credentials found for 31szglwegdhn6gw7vu4wo4rv33ya" Mar 29 18:29:14 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:14 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:14 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:14 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:14 volumio go-librespot[18397]: time="2024-03-29T18:29:14+03:00" level=debug msg="obtained new client token: AAAWm759ODMjbCIcNsO0Fp1li7JctyS0WSxZpiVHIspZBDZWrjv/d+sDKekYw5omjt5Fj5d0F6ay1P2d/JdQTwwGIjE6FWVU/o1bwUjAsMSEIftVkgI5wbm7a2xlEtZSXovhfQXQScLUGS9m3sqL2W1Vsa3HBzT4AwqBUGWdzihaF89x9Dp6G/cJSUfg46JDkfUBRyAT/WBNfFLA8pt566UZAf4utWJbjWcPuVTWCbl6ovT+eTAonnKskcUK" Mar 29 18:29:14 volumio volumio[891]: info: Initializing connection to go-librespot Websocket Mar 29 18:29:14 volumio go-librespot[18397]: time="2024-03-29T18:29:14+03:00" level=debug msg="new websocket client" Mar 29 18:29:14 volumio volumio[891]: info: Connection to go-librespot Websocket established Mar 29 18:29:14 volumio go-librespot[18397]: time="2024-03-29T18:29:14+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Mar 29 18:29:14 volumio go-librespot[18397]: time="2024-03-29T18:29:14+03:00" level=debug msg="completed keyexchange" Mar 29 18:29:15 volumio go-librespot[18397]: time="2024-03-29T18:29:15+03:00" level=debug msg="completed challenge" Mar 29 18:29:15 volumio go-librespot[18397]: time="2024-03-29T18:29:15+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 29 18:29:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 29 18:29:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 29 18:29:15 volumio volumio[891]: info: Connection to go-librespot Websocket closed Mar 29 18:29:15 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:15 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:15 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:15 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:16 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:16 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:16 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:16 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:17 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:17 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:17 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:17 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:17 volumio volumio[891]: info: Getting Spotify volume Mar 29 18:29:17 volumio volumio[891]: (node:891) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 18:29:17 volumio volumio[891]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 29 18:29:17 volumio volumio[891]: (node:891) 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: 1541) Mar 29 18:29:17 volumio volumio[891]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 6 Mar 29 18:29:17 volumio volumio[891]: info: CoreCommandRouter::volumioGetState Mar 29 18:29:17 volumio volumio[891]: info: CorePlayQueue::getTrack 0 Mar 29 18:29:18 volumio volumio[891]: info: Initializing connection to go-librespot Websocket Mar 29 18:29:18 volumio volumio[891]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 18:29:18 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:18 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:18 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:18 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:18 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 29 18:29:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4420. Mar 29 18:29:18 volumio systemd[1]: Stopped go-librespot Daemon. Mar 29 18:29:18 volumio systemd[1]: Started go-librespot Daemon. Mar 29 18:29:18 volumio go-librespot[18414]: Librespot-go daemon starting... Mar 29 18:29:18 volumio go-librespot[18414]: time="2024-03-29T18:29:18+03:00" level=info msg="generated new device id: bd0c5c2756b79dc0a3d52ac137e775e71b6e4cf8" Mar 29 18:29:18 volumio go-librespot[18414]: time="2024-03-29T18:29:18+03:00" level=debug msg="stored credentials found for 31szglwegdhn6gw7vu4wo4rv33ya" Mar 29 18:29:18 volumio go-librespot[18414]: time="2024-03-29T18:29:18+03:00" level=debug msg="obtained new client token: AAAP6bzVlX9BGGGS35o0w+z8pXlmE53iCN3Avz2Clq5OONGw7wl0BJvzwT6UFDn3KycZxtsRnrk4soamHVT4Y9NwhT6f/KcEBQXp5Q+FeMRvaqc2bYILKK7c7lUnytMgYI1jtcfSh6Ai38Z9iyNbK6bQrnxVkM5GkTDwCMNEz+V4H7p3LbO9ymkx7H9v/9UQcyh2hxICOetsS2Jb4BdpPsn1z6dWJx4HPnQDyAV1lsN7m71l/utsWsJ6GQ1e" Mar 29 18:29:18 volumio go-librespot[18414]: time="2024-03-29T18:29:18+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Mar 29 18:29:18 volumio go-librespot[18414]: time="2024-03-29T18:29:18+03:00" level=debug msg="completed keyexchange" Mar 29 18:29:19 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:19 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:19 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:19 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:19 volumio go-librespot[18414]: time="2024-03-29T18:29:19+03:00" level=debug msg="completed challenge" Mar 29 18:29:19 volumio go-librespot[18414]: time="2024-03-29T18:29:19+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 29 18:29:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 29 18:29:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 29 18:29:20 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:20 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:20 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:20 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:21 volumio volumio[891]: info: Initializing connection to go-librespot Websocket Mar 29 18:29:21 volumio volumio[891]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 18:29:21 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:21 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:21 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:21 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:22 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:22 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:22 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:22 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:22 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 29 18:29:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4421. Mar 29 18:29:22 volumio systemd[1]: Stopped go-librespot Daemon. Mar 29 18:29:22 volumio systemd[1]: Started go-librespot Daemon. Mar 29 18:29:22 volumio go-librespot[18430]: Librespot-go daemon starting... Mar 29 18:29:22 volumio go-librespot[18430]: time="2024-03-29T18:29:22+03:00" level=info msg="generated new device id: 9107a6fa8086670b61c41b297880d60e11cba24c" Mar 29 18:29:22 volumio go-librespot[18430]: time="2024-03-29T18:29:22+03:00" level=debug msg="stored credentials found for 31szglwegdhn6gw7vu4wo4rv33ya" Mar 29 18:29:22 volumio volumio[891]: info: CoreCommandRouter::volumioGetState Mar 29 18:29:22 volumio volumio[891]: info: CorePlayQueue::getTrack 0 Mar 29 18:29:22 volumio go-librespot[18430]: time="2024-03-29T18:29:22+03:00" level=debug msg="obtained new client token: AACO/L+7XTT0VdAlNkSC2e01hfRrd0KfmeJUYX54/cBj4IuNEAZ8D3VXaCbV1fAcQ/j1ghXkAQvO8YGnF4ALS+hqj9LnxeH2PzSfxK/VdLsE7gqM64tnTLV2a5TlMJlifpyoMw3axdviZSCdiY27PiOxwhRwr03UaQhlZ+dAbdEEHuY7Pcu8dE6+yyyyOo2/2RnqE7dQ6zNguRFMGlEhieetLPYv8YhF8P6EedDtONBKwb5oM8kX3XqH3l6r" Mar 29 18:29:23 volumio go-librespot[18430]: time="2024-03-29T18:29:23+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 29 18:29:23 volumio go-librespot[18430]: time="2024-03-29T18:29:23+03:00" level=debug msg="completed keyexchange" Mar 29 18:29:23 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:23 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:23 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:23 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:23 volumio go-librespot[18430]: time="2024-03-29T18:29:23+03:00" level=debug msg="completed challenge" Mar 29 18:29:23 volumio go-librespot[18430]: time="2024-03-29T18:29:23+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 29 18:29:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 29 18:29:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 29 18:29:24 volumio volumio[891]: info: Initializing connection to go-librespot Websocket Mar 29 18:29:24 volumio volumio[891]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 18:29:24 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:24 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:24 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:24 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:25 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:25 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:25 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:25 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:26 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:26 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:26 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:26 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:26 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 29 18:29:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4422. Mar 29 18:29:26 volumio systemd[1]: Stopped go-librespot Daemon. Mar 29 18:29:26 volumio systemd[1]: Started go-librespot Daemon. Mar 29 18:29:26 volumio go-librespot[18446]: Librespot-go daemon starting... Mar 29 18:29:26 volumio go-librespot[18446]: time="2024-03-29T18:29:26+03:00" level=info msg="generated new device id: a49eb6b04a7bab2627e0bbbb28403301bb99b729" Mar 29 18:29:26 volumio go-librespot[18446]: time="2024-03-29T18:29:26+03:00" level=debug msg="stored credentials found for 31szglwegdhn6gw7vu4wo4rv33ya" Mar 29 18:29:27 volumio go-librespot[18446]: time="2024-03-29T18:29:27+03:00" level=debug msg="obtained new client token: AACDQF/4IjpPR3ewYCNTZ81Kc8ifiiI6epn25xqj9fq5n4KUJyqCl9hUKOssAClYj4xxtZK1E+IskV4BeQrFsW7pIIKH50eNMy1BYfFgqcJ665dB2zAlqSToljckIwRL6B7b7Qj5rcL8voK/EGo0aJ4AgOXXTTRfmPWuot4suV9dHM3zXuQxdoCfjrw0hci9zlJIkeeQzmIhY7yxz/r86XZM/lJj5rCoLYTHVjXx7cQxMZd7CmKskIbWRA==" Mar 29 18:29:27 volumio volumio[891]: info: Initializing connection to go-librespot Websocket Mar 29 18:29:27 volumio go-librespot[18446]: time="2024-03-29T18:29:27+03:00" level=debug msg="new websocket client" Mar 29 18:29:27 volumio volumio[891]: info: Connection to go-librespot Websocket established Mar 29 18:29:27 volumio go-librespot[18446]: time="2024-03-29T18:29:27+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Mar 29 18:29:27 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:27 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:27 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:27 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:27 volumio go-librespot[18446]: time="2024-03-29T18:29:27+03:00" level=debug msg="completed keyexchange" Mar 29 18:29:27 volumio go-librespot[18446]: time="2024-03-29T18:29:27+03:00" level=debug msg="completed challenge" Mar 29 18:29:27 volumio go-librespot[18446]: time="2024-03-29T18:29:27+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 29 18:29:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 29 18:29:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 29 18:29:27 volumio volumio[891]: info: Connection to go-librespot Websocket closed Mar 29 18:29:28 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:28 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:28 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:28 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:29 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:29 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:29 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:29 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:30 volumio volumio[891]: info: Getting Spotify volume Mar 29 18:29:30 volumio volumio[891]: (node:891) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 18:29:30 volumio volumio[891]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 29 18:29:30 volumio volumio[891]: (node:891) 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: 1542) Mar 29 18:29:30 volumio volumio[891]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 6 Mar 29 18:29:30 volumio volumio[891]: info: CoreCommandRouter::volumioGetState Mar 29 18:29:30 volumio volumio[891]: info: CorePlayQueue::getTrack 0 Mar 29 18:29:30 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:30 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:30 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:30 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:30 volumio volumio[891]: info: Initializing connection to go-librespot Websocket Mar 29 18:29:30 volumio volumio[891]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 18:29:31 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 29 18:29:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4423. Mar 29 18:29:31 volumio systemd[1]: Stopped go-librespot Daemon. Mar 29 18:29:31 volumio systemd[1]: Started go-librespot Daemon. Mar 29 18:29:31 volumio go-librespot[18464]: Librespot-go daemon starting... Mar 29 18:29:31 volumio go-librespot[18464]: time="2024-03-29T18:29:31+03:00" level=info msg="generated new device id: d2d098e63663f17464617f48fc2cab6baa06ba07" Mar 29 18:29:31 volumio go-librespot[18464]: time="2024-03-29T18:29:31+03:00" level=debug msg="stored credentials found for 31szglwegdhn6gw7vu4wo4rv33ya" Mar 29 18:29:31 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:31 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:31 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:31 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:31 volumio go-librespot[18464]: time="2024-03-29T18:29:31+03:00" level=debug msg="obtained new client token: AAB0oyHua6ipntrkMVFqWHspQM/AIQoi1kNPb08S7UhNtHWEgCeCnT24cVGOPGQYNQRqGa27EtHX93v/gl4BFutpniLdmb7TuQEN+KTWaaaKbc6uFW1fyfC+SgcfTOK0HcbzWEZXzLzquSJVp0XkDMbM2q/IaoRRecact7hrAzmUqWpXLLviNXoGQiNJ8QAAvRo/mj7zVSLt3i+32W7lW4cyrDhBrwlcnXlYolKyLiIBVDzwtoGeXHPFundv" Mar 29 18:29:31 volumio go-librespot[18464]: time="2024-03-29T18:29:31+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Mar 29 18:29:31 volumio go-librespot[18464]: time="2024-03-29T18:29:31+03:00" level=debug msg="completed keyexchange" Mar 29 18:29:32 volumio go-librespot[18464]: time="2024-03-29T18:29:32+03:00" level=debug msg="completed challenge" Mar 29 18:29:32 volumio go-librespot[18464]: time="2024-03-29T18:29:32+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 29 18:29:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 29 18:29:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 29 18:29:32 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:32 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:32 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:32 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:32 volumio volumio[891]: info: CoreCommandRouter::volumioGetState Mar 29 18:29:32 volumio volumio[891]: info: CorePlayQueue::getTrack 0 Mar 29 18:29:32 volumio volumio[891]: info: Listing playlists Mar 29 18:29:32 volumio volumio[891]: info: Listing playlists Mar 29 18:29:33 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:33 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:33 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:33 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:33 volumio volumio[891]: info: Initializing connection to go-librespot Websocket Mar 29 18:29:33 volumio volumio[891]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 18:29:34 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:34 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:34 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:34 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:35 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:35 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:35 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:35 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:35 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 29 18:29:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4424. Mar 29 18:29:35 volumio systemd[1]: Stopped go-librespot Daemon. Mar 29 18:29:35 volumio systemd[1]: Started go-librespot Daemon. Mar 29 18:29:35 volumio go-librespot[18481]: Librespot-go daemon starting... Mar 29 18:29:35 volumio go-librespot[18481]: time="2024-03-29T18:29:35+03:00" level=info msg="generated new device id: 2581d12c8f8bd66caef7f2598588d3b09eadd89b" Mar 29 18:29:35 volumio go-librespot[18481]: time="2024-03-29T18:29:35+03:00" level=debug msg="stored credentials found for 31szglwegdhn6gw7vu4wo4rv33ya" Mar 29 18:29:35 volumio go-librespot[18481]: time="2024-03-29T18:29:35+03:00" level=debug msg="obtained new client token: AABK6URWbLx1IhReAAqnGRfjpEVqul7JQRb+KLleNRrP6C+kRsnLaKl7Y5yxK/2x2LSoVMapFZjKd//iWGaUQW50TwH8AvHTU/FagpNM6Gye8R9kItlGdAmVfD4E/9+Uyg8HGWY5rw8lS3lfMAqFHTFaVKa6jzBuZOa9DyU+HX2ptaRctIHUeomO3KbYOoeNn4oJARQ1lQsWYirb5JyyPp12CecjwktS62f9xQKHKIWs84AHnOtJXMzCHra1" Mar 29 18:29:35 volumio go-librespot[18481]: time="2024-03-29T18:29:35+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Mar 29 18:29:35 volumio go-librespot[18481]: time="2024-03-29T18:29:35+03:00" level=debug msg="completed keyexchange" Mar 29 18:29:36 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:36 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:36 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:36 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:36 volumio go-librespot[18481]: time="2024-03-29T18:29:36+03:00" level=debug msg="completed challenge" Mar 29 18:29:36 volumio volumio[891]: info: Initializing connection to go-librespot Websocket Mar 29 18:29:36 volumio go-librespot[18481]: time="2024-03-29T18:29:36+03:00" level=debug msg="new websocket client" Mar 29 18:29:36 volumio volumio[891]: info: Connection to go-librespot Websocket established Mar 29 18:29:37 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:37 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:37 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:37 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:37 volumio go-librespot[18481]: time="2024-03-29T18:29:37+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 29 18:29:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 29 18:29:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 29 18:29:37 volumio volumio[891]: info: Connection to go-librespot Websocket closed Mar 29 18:29:38 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:38 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:38 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:38 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:39 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:39 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:39 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:39 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:39 volumio volumio[891]: info: Getting Spotify volume Mar 29 18:29:39 volumio volumio[891]: (node:891) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 18:29:39 volumio volumio[891]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 29 18:29:39 volumio volumio[891]: (node:891) 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: 1543) Mar 29 18:29:39 volumio volumio[891]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 6 Mar 29 18:29:40 volumio volumio[891]: info: CoreCommandRouter::volumioGetState Mar 29 18:29:40 volumio volumio[891]: info: CorePlayQueue::getTrack 0 Mar 29 18:29:40 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:40 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:40 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:40 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:40 volumio volumio[891]: info: Initializing connection to go-librespot Websocket Mar 29 18:29:40 volumio volumio[891]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 18:29:40 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 29 18:29:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4425. Mar 29 18:29:40 volumio systemd[1]: Stopped go-librespot Daemon. Mar 29 18:29:40 volumio systemd[1]: Started go-librespot Daemon. Mar 29 18:29:40 volumio go-librespot[18500]: Librespot-go daemon starting... Mar 29 18:29:40 volumio go-librespot[18500]: time="2024-03-29T18:29:40+03:00" level=info msg="generated new device id: 0e4e8b93cd2a5164166f85de6a7484f60560da65" Mar 29 18:29:40 volumio go-librespot[18500]: time="2024-03-29T18:29:40+03:00" level=debug msg="stored credentials found for 31szglwegdhn6gw7vu4wo4rv33ya" Mar 29 18:29:40 volumio go-librespot[18500]: time="2024-03-29T18:29:40+03:00" level=debug msg="obtained new client token: AAATC4tA5WAb5uM1eR3qfuuPF8nImSS0ZVuSESU7/VGuLTvQRpO/RGor+lw8LDMhsFGgvl37IzXjaLhGWqN3hWvzcxpNsMR0M8V+6ZddcQp8VRYuS9VUAdDspa89uPQDeSb25fSlA9ktq+wckn3I5yPYgwR//q9GaRKzf2BZi+C0EsU/SyxMnMLITZAJU7AEq8Ufz6iauTYtxWmRxXK3NIOtygN7lsynfTmPPkScqM7x4w+DmULkfm4KUVk1" Mar 29 18:29:40 volumio go-librespot[18500]: time="2024-03-29T18:29:40+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 29 18:29:41 volumio go-librespot[18500]: time="2024-03-29T18:29:41+03:00" level=debug msg="completed keyexchange" Mar 29 18:29:41 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:41 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:41 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:41 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:41 volumio go-librespot[18500]: time="2024-03-29T18:29:41+03:00" level=debug msg="completed challenge" Mar 29 18:29:41 volumio go-librespot[18500]: time="2024-03-29T18:29:41+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 29 18:29:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 29 18:29:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 29 18:29:42 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:42 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:42 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:42 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:42 volumio volumio[891]: info: CoreCommandRouter::volumioGetState Mar 29 18:29:42 volumio volumio[891]: info: CorePlayQueue::getTrack 0 Mar 29 18:29:43 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:43 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:43 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:43 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:43 volumio volumio[891]: info: Initializing connection to go-librespot Websocket Mar 29 18:29:43 volumio volumio[891]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 18:29:44 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:44 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:44 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:44 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:44 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 29 18:29:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4426. Mar 29 18:29:44 volumio systemd[1]: Stopped go-librespot Daemon. Mar 29 18:29:44 volumio systemd[1]: Started go-librespot Daemon. Mar 29 18:29:44 volumio go-librespot[18516]: Librespot-go daemon starting... Mar 29 18:29:44 volumio go-librespot[18516]: time="2024-03-29T18:29:44+03:00" level=info msg="generated new device id: 7805d2c1bf10636e01dcccbbbe9e0ac0e3933417" Mar 29 18:29:44 volumio go-librespot[18516]: time="2024-03-29T18:29:44+03:00" level=debug msg="stored credentials found for 31szglwegdhn6gw7vu4wo4rv33ya" Mar 29 18:29:45 volumio go-librespot[18516]: time="2024-03-29T18:29:45+03:00" level=debug msg="obtained new client token: AAD3lN9SLEUk1CWNCaphU5En1cL3ItB6hE4QSgIkpx8AixDNAfh0/jXZ4SBKYdAqcLP1jaRbdBixEzwqA1UTwiWfn0uhLy3nL/gGAf7kheJJHy4jIbAgOtdHt07I21DGPYWqDPO3Cy9Fr/kyMmM1Hn+iePE0l7l7y4UI3vit3TA/COX4qWwNOymAR3+Nb4YKyULjeRKtBzgxVyJyskMfBVJmTiKADXuO2dhAKlS7hTchTfOOBaENOiyIBg==" Mar 29 18:29:45 volumio go-librespot[18516]: time="2024-03-29T18:29:45+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 29 18:29:45 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:45 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:45 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:45 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:45 volumio go-librespot[18516]: time="2024-03-29T18:29:45+03:00" level=debug msg="completed keyexchange" Mar 29 18:29:45 volumio go-librespot[18516]: time="2024-03-29T18:29:45+03:00" level=debug msg="completed challenge" Mar 29 18:29:45 volumio go-librespot[18516]: time="2024-03-29T18:29:45+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 29 18:29:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 29 18:29:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 29 18:29:46 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:46 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:46 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:46 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:46 volumio volumio[891]: info: Initializing connection to go-librespot Websocket Mar 29 18:29:46 volumio volumio[891]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 18:29:47 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:47 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:47 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:47 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:48 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:48 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:48 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:48 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:49 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 29 18:29:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4427. Mar 29 18:29:49 volumio systemd[1]: Stopped go-librespot Daemon. Mar 29 18:29:49 volumio systemd[1]: Started go-librespot Daemon. Mar 29 18:29:49 volumio go-librespot[18535]: Librespot-go daemon starting... Mar 29 18:29:49 volumio go-librespot[18535]: time="2024-03-29T18:29:49+03:00" level=info msg="generated new device id: 7cc88e9a4d05f6c53decd5846462edf99c21544a" Mar 29 18:29:49 volumio go-librespot[18535]: time="2024-03-29T18:29:49+03:00" level=debug msg="stored credentials found for 31szglwegdhn6gw7vu4wo4rv33ya" Mar 29 18:29:49 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:49 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:49 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:49 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:49 volumio go-librespot[18535]: time="2024-03-29T18:29:49+03:00" level=debug msg="obtained new client token: AAA7x/yGFBpbPqS/NR3ipqQIswha2k7ZOAvTqM76EuZ53uIbvoz/Aoygp/Ka3mlXzAzGcBniewjSLTLRW0elKSQLThGV/kDmzE25U9LUCs7fd6POKCF9ZHzg9mnXHe3VjqTeZ4MY4Lm8+wvkv9YciEhR2ysBrBcC0QyBbj7mA3iVrBb2O5fe0yIkddznzwzptUSInWTu26bK9yBvoRGLheaMAY5LZKBLhqeTI/Kd0eiWERT/hlaTrH/mYCbx" Mar 29 18:29:49 volumio go-librespot[18535]: time="2024-03-29T18:29:49+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Mar 29 18:29:49 volumio volumio[891]: info: Initializing connection to go-librespot Websocket Mar 29 18:29:49 volumio volumio[891]: info: Connection to go-librespot Websocket established Mar 29 18:29:49 volumio go-librespot[18535]: time="2024-03-29T18:29:49+03:00" level=debug msg="new websocket client" Mar 29 18:29:49 volumio go-librespot[18535]: time="2024-03-29T18:29:49+03:00" level=debug msg="completed keyexchange" Mar 29 18:29:50 volumio go-librespot[18535]: time="2024-03-29T18:29:50+03:00" level=debug msg="completed challenge" Mar 29 18:29:50 volumio go-librespot[18535]: time="2024-03-29T18:29:50+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 29 18:29:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 29 18:29:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 29 18:29:50 volumio volumio[891]: info: Connection to go-librespot Websocket closed Mar 29 18:29:50 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:50 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:50 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:50 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:51 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:51 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:51 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:51 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:52 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:52 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:52 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:52 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:52 volumio volumio[891]: info: Getting Spotify volume Mar 29 18:29:52 volumio volumio[891]: (node:891) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 18:29:52 volumio volumio[891]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 29 18:29:52 volumio volumio[891]: (node:891) 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: 1544) Mar 29 18:29:52 volumio volumio[891]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 6 Mar 29 18:29:52 volumio volumio[891]: info: CoreCommandRouter::volumioGetState Mar 29 18:29:52 volumio volumio[891]: info: CorePlayQueue::getTrack 0 Mar 29 18:29:52 volumio volumio[891]: info: CoreCommandRouter::volumioGetState Mar 29 18:29:52 volumio volumio[891]: info: CorePlayQueue::getTrack 0 Mar 29 18:29:52 volumio volumio[891]: info: Listing playlists Mar 29 18:29:52 volumio volumio[891]: info: Listing playlists Mar 29 18:29:53 volumio volumio[891]: info: Initializing connection to go-librespot Websocket Mar 29 18:29:53 volumio volumio[891]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 18:29:53 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:53 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:53 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:53 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:53 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 29 18:29:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4428. Mar 29 18:29:53 volumio systemd[1]: Stopped go-librespot Daemon. Mar 29 18:29:53 volumio systemd[1]: Started go-librespot Daemon. Mar 29 18:29:53 volumio go-librespot[18555]: Librespot-go daemon starting... Mar 29 18:29:53 volumio go-librespot[18555]: time="2024-03-29T18:29:53+03:00" level=info msg="generated new device id: 8c70bab7964298662b6b02796893dca70f1e0cff" Mar 29 18:29:53 volumio go-librespot[18555]: time="2024-03-29T18:29:53+03:00" level=debug msg="stored credentials found for 31szglwegdhn6gw7vu4wo4rv33ya" Mar 29 18:29:53 volumio go-librespot[18555]: time="2024-03-29T18:29:53+03:00" level=debug msg="obtained new client token: AACpbHel08XtIi7LRK1f0OKDPxHyJs6rIkBZaBdR1oGe9cciCg7C0faUweL8YpRpuWuf00O68OIY6LiLMHH6dHDMKKPtaQJjqqMobijshltBbr7hFX/suXgdU0EW7PXt1VvvLW6KhAT9qp2Oagyzk0LWvIN6RboKIQbC6gTVvPM+z3YDMRNIa7tkPMXUqNamdIcOBB9ZuvkC2rgHK0PkwudiH21yAd67vqJVmXjKBHGgcmAkBZs2fmfnOY4A" Mar 29 18:29:53 volumio go-librespot[18555]: time="2024-03-29T18:29:53+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Mar 29 18:29:53 volumio go-librespot[18555]: time="2024-03-29T18:29:53+03:00" level=debug msg="completed keyexchange" Mar 29 18:29:54 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:54 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:54 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:54 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:54 volumio go-librespot[18555]: time="2024-03-29T18:29:54+03:00" level=debug msg="completed challenge" Mar 29 18:29:54 volumio go-librespot[18555]: time="2024-03-29T18:29:54+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 29 18:29:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 29 18:29:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 29 18:29:55 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:55 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:55 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:55 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:56 volumio volumio[891]: info: Initializing connection to go-librespot Websocket Mar 29 18:29:56 volumio volumio[891]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 18:29:56 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:56 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:56 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:56 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:57 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:57 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:57 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:57 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:57 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 29 18:29:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4429. Mar 29 18:29:57 volumio systemd[1]: Stopped go-librespot Daemon. Mar 29 18:29:57 volumio systemd[1]: Started go-librespot Daemon. Mar 29 18:29:57 volumio go-librespot[18571]: Librespot-go daemon starting... Mar 29 18:29:57 volumio go-librespot[18571]: time="2024-03-29T18:29:57+03:00" level=info msg="generated new device id: 0c8c0bb8acb4b6da9b25215d06434eae5571300f" Mar 29 18:29:57 volumio go-librespot[18571]: time="2024-03-29T18:29:57+03:00" level=debug msg="stored credentials found for 31szglwegdhn6gw7vu4wo4rv33ya" Mar 29 18:29:57 volumio go-librespot[18571]: time="2024-03-29T18:29:57+03:00" level=debug msg="obtained new client token: AAA4+mlLDz2pvQRxtZB6hjP5OFxe8kFc2w+dJxYSwtn48jxTXnlq+Jx77VieBSb09JXrzuBsRwKJc8YXUDV3Kys4sO7TiWeYnVhOckTSuQt5p8fK1x+OWtvPI8NWNqJS7R7AJX9xrOv21NDYBfljDUQT2DEiK5ESldD492tL3H8EwpLFAZeRA24vlt7Y0SF7kEvMODG8Hxk8Ptk0ge1FH+DJxq7/RawzuvsijbJTV8SUxCN0GX4QL127qVKA" Mar 29 18:29:57 volumio go-librespot[18571]: time="2024-03-29T18:29:57+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 29 18:29:58 volumio go-librespot[18571]: time="2024-03-29T18:29:58+03:00" level=debug msg="completed keyexchange" Mar 29 18:29:58 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:58 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:58 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:58 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:58 volumio go-librespot[18571]: time="2024-03-29T18:29:58+03:00" level=debug msg="completed challenge" Mar 29 18:29:58 volumio go-librespot[18571]: time="2024-03-29T18:29:58+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 29 18:29:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 29 18:29:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 29 18:29:59 volumio volumio[891]: info: Initializing connection to go-librespot Websocket Mar 29 18:29:59 volumio volumio[891]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 18:29:59 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:59 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:29:59 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:29:59 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:00 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:00 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:00 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:00 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:01 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:01 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:01 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:01 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:01 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 29 18:30:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4430. Mar 29 18:30:01 volumio systemd[1]: Stopped go-librespot Daemon. Mar 29 18:30:01 volumio systemd[1]: Started go-librespot Daemon. Mar 29 18:30:01 volumio go-librespot[18587]: Librespot-go daemon starting... Mar 29 18:30:01 volumio go-librespot[18587]: time="2024-03-29T18:30:01+03:00" level=info msg="generated new device id: f2b2b554df905f5f81358e171df8c51f2f693805" Mar 29 18:30:01 volumio go-librespot[18587]: time="2024-03-29T18:30:01+03:00" level=debug msg="stored credentials found for 31szglwegdhn6gw7vu4wo4rv33ya" Mar 29 18:30:02 volumio go-librespot[18587]: time="2024-03-29T18:30:02+03:00" level=debug msg="obtained new client token: AADyY2Fl3ZzpbcaLjkovwvNQ8m+4CGqGFbbioxl4tpiebL8WL5u0Icff+P0mlyhopTSpN10Li2Kg6RTWbtGbM2c9Kwj8mIrp8/D27Pg3dQqpTHO5EOy9Q/OcqDpNM3aq7wWsSsW3XmBAi3WEl2q9C6iJXLPFm71G28FWcXS+DADUJOmBDutum49qyq912abWu3A499xHnFWgrS8j8VavjwFSnak0+voMIAuN+svlGQND07vrtsJzsupyFA==" Mar 29 18:30:02 volumio volumio[891]: info: Initializing connection to go-librespot Websocket Mar 29 18:30:02 volumio volumio[891]: info: Connection to go-librespot Websocket established Mar 29 18:30:02 volumio go-librespot[18587]: time="2024-03-29T18:30:02+03:00" level=debug msg="new websocket client" Mar 29 18:30:02 volumio go-librespot[18587]: time="2024-03-29T18:30:02+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 29 18:30:02 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:02 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:02 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:02 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:02 volumio volumio[891]: info: CoreCommandRouter::volumioGetState Mar 29 18:30:02 volumio volumio[891]: info: CorePlayQueue::getTrack 0 Mar 29 18:30:03 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:03 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:03 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:03 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:04 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:04 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:04 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:04 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:05 volumio volumio[891]: info: Getting Spotify volume Mar 29 18:30:05 volumio volumio[891]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 6 Mar 29 18:30:05 volumio volumio[891]: info: CoreCommandRouter::volumioGetState Mar 29 18:30:05 volumio volumio[891]: info: CorePlayQueue::getTrack 0 Mar 29 18:30:05 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:05 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:05 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:05 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:06 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:06 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:06 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:06 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:07 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:07 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:07 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:07 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:07 volumio go-librespot[18587]: time="2024-03-29T18:30:07+03:00" level=debug msg="completed keyexchange" Mar 29 18:30:07 volumio go-librespot[18587]: time="2024-03-29T18:30:07+03:00" level=debug msg="completed challenge" Mar 29 18:30:08 volumio go-librespot[18587]: time="2024-03-29T18:30:08+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 29 18:30:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 29 18:30:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 29 18:30:08 volumio volumio[891]: (node:891) UnhandledPromiseRejectionWarning: Error: socket hang up Mar 29 18:30:08 volumio volumio[891]: at connResetException (internal/errors.js:607:14) Mar 29 18:30:08 volumio volumio[891]: at Socket.socketOnEnd (_http_client.js:493:23) Mar 29 18:30:08 volumio volumio[891]: at Socket.emit (events.js:327:22) Mar 29 18:30:08 volumio volumio[891]: at endReadableNT (internal/streams/readable.js:1327:12) Mar 29 18:30:08 volumio volumio[891]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Mar 29 18:30:08 volumio volumio[891]: (node:891) 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: 1545) Mar 29 18:30:08 volumio volumio[891]: info: Connection to go-librespot Websocket closed Mar 29 18:30:08 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:08 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:08 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:08 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:09 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:09 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:09 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:09 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:10 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:10 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:10 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:10 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:11 volumio volumio[891]: info: Initializing connection to go-librespot Websocket Mar 29 18:30:11 volumio volumio[891]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 18:30:11 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 29 18:30:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4431. Mar 29 18:30:11 volumio systemd[1]: Stopped go-librespot Daemon. Mar 29 18:30:11 volumio systemd[1]: Started go-librespot Daemon. Mar 29 18:30:11 volumio go-librespot[18651]: Librespot-go daemon starting... Mar 29 18:30:11 volumio go-librespot[18651]: time="2024-03-29T18:30:11+03:00" level=info msg="generated new device id: 53b7c7de12a0b3a11d156b399b001411109977a3" Mar 29 18:30:11 volumio go-librespot[18651]: time="2024-03-29T18:30:11+03:00" level=debug msg="stored credentials found for 31szglwegdhn6gw7vu4wo4rv33ya" Mar 29 18:30:11 volumio go-librespot[18651]: time="2024-03-29T18:30:11+03:00" level=debug msg="obtained new client token: AAB7C1A2Fy3f6LMz/LCDCGpj+CjXwuad9fJjNLmUX62buS4O8N70HBqKmbSsZOMG0fxHVflJR492RqGP4+gu04llleqJC2Z2gsubmPzBFHgWHm/4xui5nWD1FYX/oMlqibRiddZflyaZkdtxlyhNddEqf1G+5Y4giJEJ4OBbKSmK9iw5IkfCkaAuPzU+gzQj2I4xZyWgntGQSKcybGS8G11yaleS8/G7h8e1zS7SJN490/lYJ3rqz6wawXVj" Mar 29 18:30:11 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:11 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:11 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:11 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:11 volumio go-librespot[18651]: time="2024-03-29T18:30:11+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 29 18:30:11 volumio go-librespot[18651]: time="2024-03-29T18:30:11+03:00" level=debug msg="completed keyexchange" Mar 29 18:30:12 volumio go-librespot[18651]: time="2024-03-29T18:30:12+03:00" level=debug msg="completed challenge" Mar 29 18:30:12 volumio go-librespot[18651]: time="2024-03-29T18:30:12+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 29 18:30:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 29 18:30:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 29 18:30:12 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:12 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:12 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:12 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:12 volumio volumio[891]: info: CoreCommandRouter::volumioGetState Mar 29 18:30:12 volumio volumio[891]: info: CorePlayQueue::getTrack 0 Mar 29 18:30:12 volumio volumio[891]: info: Listing playlists Mar 29 18:30:12 volumio volumio[891]: info: Listing playlists Mar 29 18:30:13 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:13 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:13 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:13 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:14 volumio volumio[891]: info: Initializing connection to go-librespot Websocket Mar 29 18:30:14 volumio volumio[891]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 18:30:14 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:14 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:14 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:14 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:15 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:15 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:15 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:15 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:15 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 29 18:30:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4432. Mar 29 18:30:15 volumio systemd[1]: Stopped go-librespot Daemon. Mar 29 18:30:15 volumio systemd[1]: Started go-librespot Daemon. Mar 29 18:30:15 volumio go-librespot[18668]: Librespot-go daemon starting... Mar 29 18:30:15 volumio go-librespot[18668]: time="2024-03-29T18:30:15+03:00" level=info msg="generated new device id: 8181c6e8e2cfffa58724896a45803a43fc9ea522" Mar 29 18:30:15 volumio go-librespot[18668]: time="2024-03-29T18:30:15+03:00" level=debug msg="stored credentials found for 31szglwegdhn6gw7vu4wo4rv33ya" Mar 29 18:30:15 volumio go-librespot[18668]: time="2024-03-29T18:30:15+03:00" level=debug msg="obtained new client token: AABf+i/KJLzIduHT2d1KU7RptmPubOiL7crMBoH97Ffac4TCpZ8Z8ZEZoDCxQcowf8Ufmt22/9YYKdoczQyo6VGEcn5UxE7c+nLq9y09N0sCD1pxia8yHRWUrGUBrKIt/ECJBATc5XeOYX02imTJZc0KRj6IxYR7oFXjoVJVRJwzJdBlLI3eEU5eUAGYVkv4IsGmwcP2JyGM20CITbRF1Ky9HFGxYkRPH8Z9BrAQ5xz590l6EyRuKPiRE2BP" Mar 29 18:30:15 volumio go-librespot[18668]: time="2024-03-29T18:30:15+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 29 18:30:15 volumio go-librespot[18668]: time="2024-03-29T18:30:15+03:00" level=debug msg="completed keyexchange" Mar 29 18:30:16 volumio go-librespot[18668]: time="2024-03-29T18:30:16+03:00" level=debug msg="completed challenge" Mar 29 18:30:16 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:16 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:16 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:16 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:16 volumio go-librespot[18668]: time="2024-03-29T18:30:16+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 29 18:30:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 29 18:30:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 29 18:30:17 volumio volumio[891]: info: Initializing connection to go-librespot Websocket Mar 29 18:30:17 volumio volumio[891]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 18:30:17 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:17 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:17 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:17 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:18 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:18 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:18 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:18 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:19 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:19 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:19 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:19 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:19 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 29 18:30:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4433. Mar 29 18:30:19 volumio systemd[1]: Stopped go-librespot Daemon. Mar 29 18:30:19 volumio systemd[1]: Started go-librespot Daemon. Mar 29 18:30:19 volumio go-librespot[18684]: Librespot-go daemon starting... Mar 29 18:30:19 volumio go-librespot[18684]: time="2024-03-29T18:30:19+03:00" level=info msg="generated new device id: 71d6ccf255065be45e897dd6cdcaa375491419e0" Mar 29 18:30:19 volumio go-librespot[18684]: time="2024-03-29T18:30:19+03:00" level=debug msg="stored credentials found for 31szglwegdhn6gw7vu4wo4rv33ya" Mar 29 18:30:19 volumio go-librespot[18684]: time="2024-03-29T18:30:19+03:00" level=debug msg="obtained new client token: AAANOyCxU7V5ryY2LzHoLIYH7iLkZlRhvtDiUASyZuNTsyyLWmIs+pPMKbcXxKJCwa6rBj9rExQNgvfRkDa5pvPn4kEmSMcSfOJAzv6jD8fIeuPKYxI2Dq1LXeVedzbWEcI71dLThBCNwmx9jmTse8n0Xc29iEqboqaIQGdHhXezZAm9eiirrLOcMjabv00PjJiwXx4UwZ0l9BMNqlPrKeAPdNAjt/p8pWu3SkzKwWqd9HzM5QrbvRRBbq7x" Mar 29 18:30:19 volumio go-librespot[18684]: time="2024-03-29T18:30:19+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Mar 29 18:30:20 volumio volumio[891]: info: Initializing connection to go-librespot Websocket Mar 29 18:30:20 volumio go-librespot[18684]: time="2024-03-29T18:30:20+03:00" level=debug msg="new websocket client" Mar 29 18:30:20 volumio volumio[891]: info: Connection to go-librespot Websocket established Mar 29 18:30:20 volumio go-librespot[18684]: time="2024-03-29T18:30:20+03:00" level=debug msg="completed keyexchange" Mar 29 18:30:20 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:20 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:20 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:20 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:20 volumio go-librespot[18684]: time="2024-03-29T18:30:20+03:00" level=debug msg="completed challenge" Mar 29 18:30:20 volumio go-librespot[18684]: time="2024-03-29T18:30:20+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 29 18:30:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 29 18:30:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 29 18:30:20 volumio volumio[891]: info: Connection to go-librespot Websocket closed Mar 29 18:30:21 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:21 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:21 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:21 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:22 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:22 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:22 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:22 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:22 volumio volumio[891]: info: CoreCommandRouter::volumioGetState Mar 29 18:30:22 volumio volumio[891]: info: CorePlayQueue::getTrack 0 Mar 29 18:30:23 volumio volumio[891]: info: Getting Spotify volume Mar 29 18:30:23 volumio volumio[891]: (node:891) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 18:30:23 volumio volumio[891]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 29 18:30:23 volumio volumio[891]: (node:891) 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: 1546) Mar 29 18:30:23 volumio volumio[891]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 6 Mar 29 18:30:23 volumio volumio[891]: info: CoreCommandRouter::volumioGetState Mar 29 18:30:23 volumio volumio[891]: info: CorePlayQueue::getTrack 0 Mar 29 18:30:23 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:23 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:23 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:23 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:23 volumio volumio[891]: info: Initializing connection to go-librespot Websocket Mar 29 18:30:23 volumio volumio[891]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 18:30:23 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 29 18:30:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4434. Mar 29 18:30:23 volumio systemd[1]: Stopped go-librespot Daemon. Mar 29 18:30:23 volumio systemd[1]: Started go-librespot Daemon. Mar 29 18:30:23 volumio go-librespot[18702]: Librespot-go daemon starting... Mar 29 18:30:23 volumio go-librespot[18702]: time="2024-03-29T18:30:23+03:00" level=info msg="generated new device id: 4a04226f4753243d9dc5636ac780f69dbed617d0" Mar 29 18:30:23 volumio go-librespot[18702]: time="2024-03-29T18:30:23+03:00" level=debug msg="stored credentials found for 31szglwegdhn6gw7vu4wo4rv33ya" Mar 29 18:30:24 volumio go-librespot[18702]: time="2024-03-29T18:30:24+03:00" level=debug msg="obtained new client token: AABSoxQ+JcbBIWpykjDBtw7EPDDSSmOMFyL8Ia22UVquw7TCwuo94oZSZnJEPVwdRIAOLtkcsrehelRelpbjQLE1f2jBqFW0FwIa0gxRK3zQEfhbeY8NX0N6mEB+E/YC0UL4SM2LXBoShwjF34DJInedvELgQgMml+fddezYAxGTsS0e0wKcy55lfprpxUCpn4TuvfFv+PtXLwHlZ/gc0CdB6fwtEBUkHoqlCnhJLMzmXHIGBMGRMUSr7g==" Mar 29 18:30:24 volumio go-librespot[18702]: time="2024-03-29T18:30:24+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Mar 29 18:30:24 volumio go-librespot[18702]: time="2024-03-29T18:30:24+03:00" level=debug msg="completed keyexchange" Mar 29 18:30:24 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:24 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:24 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:24 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:24 volumio go-librespot[18702]: time="2024-03-29T18:30:24+03:00" level=debug msg="completed challenge" Mar 29 18:30:24 volumio go-librespot[18702]: time="2024-03-29T18:30:24+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 29 18:30:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 29 18:30:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 29 18:30:25 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:25 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:25 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:25 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:26 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:26 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:26 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:26 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:26 volumio volumio[891]: info: Initializing connection to go-librespot Websocket Mar 29 18:30:26 volumio volumio[891]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 18:30:27 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:27 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:27 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:27 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:28 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 29 18:30:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4435. Mar 29 18:30:28 volumio systemd[1]: Stopped go-librespot Daemon. Mar 29 18:30:28 volumio systemd[1]: Started go-librespot Daemon. Mar 29 18:30:28 volumio go-librespot[18718]: Librespot-go daemon starting... Mar 29 18:30:28 volumio go-librespot[18718]: time="2024-03-29T18:30:28+03:00" level=info msg="generated new device id: 543fcae5970107d024fbab1beab727b55a721288" Mar 29 18:30:28 volumio go-librespot[18718]: time="2024-03-29T18:30:28+03:00" level=debug msg="stored credentials found for 31szglwegdhn6gw7vu4wo4rv33ya" Mar 29 18:30:28 volumio go-librespot[18718]: time="2024-03-29T18:30:28+03:00" level=debug msg="obtained new client token: AABktAptKmkGB/ddJhPPnj3xJF1RAF4LfyMV7rXUYyIMZzYl+NNgG54Bosm8dhr7TkDAj2ysVeTTfvN2e9N/A/Zf9Pm6SdLoxsapkjh5mFFSMuSCGLdS3lE4Mlw059vCTvF/GP9MLhGhB3fdcCRceMMoClqLCq/XrAXhAdoudewQRF18WjDtfkx52wiG5dK6W4UcS4ipZDJ0LsOgsxt35yJ2U1kW71p7ieMtrvoI6U8C9gkOfr19wcssK+R5" Mar 29 18:30:28 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:28 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:28 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:28 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:28 volumio go-librespot[18718]: time="2024-03-29T18:30:28+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 29 18:30:28 volumio go-librespot[18718]: time="2024-03-29T18:30:28+03:00" level=debug msg="completed keyexchange" Mar 29 18:30:29 volumio go-librespot[18718]: time="2024-03-29T18:30:29+03:00" level=debug msg="completed challenge" Mar 29 18:30:29 volumio go-librespot[18718]: time="2024-03-29T18:30:29+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 29 18:30:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 29 18:30:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 29 18:30:29 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:29 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:29 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:29 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:29 volumio volumio[891]: info: Initializing connection to go-librespot Websocket Mar 29 18:30:29 volumio volumio[891]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 18:30:30 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:30 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:30 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:30 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:31 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:31 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:31 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:31 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:32 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 29 18:30:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4436. Mar 29 18:30:32 volumio systemd[1]: Stopped go-librespot Daemon. Mar 29 18:30:32 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:32 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:32 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:32 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:32 volumio systemd[1]: Started go-librespot Daemon. Mar 29 18:30:32 volumio go-librespot[18734]: Librespot-go daemon starting... Mar 29 18:30:32 volumio go-librespot[18734]: time="2024-03-29T18:30:32+03:00" level=info msg="generated new device id: 87e6b31d4982ca5e20f84ce6b9eba55b1d509db1" Mar 29 18:30:32 volumio go-librespot[18734]: time="2024-03-29T18:30:32+03:00" level=debug msg="stored credentials found for 31szglwegdhn6gw7vu4wo4rv33ya" Mar 29 18:30:32 volumio go-librespot[18734]: time="2024-03-29T18:30:32+03:00" level=debug msg="obtained new client token: AAAoiHfBqhz1h3uA5oMpVFSYdBUECcSoyQu+u4SusbCvnNdoLg+3T8QKQ8euwgE4kHxa4eYcvLH7MhVx1chgrqcDY5l+mzPiihH6bAnMka8PzBgTgHwGThuK/W9js4anklchRKfuyzs7rnypIvIj/Dd7jG+IbqliZOsHMbh+ux5LVDpa0Xf1bNiCkYgIagvQA6HOxoaPLetlU9RuKtVz3UYEyK/X8WbXU2yTXwYf5XSuz/ricVTDX3UNF4sy" Mar 29 18:30:32 volumio volumio[891]: info: Initializing connection to go-librespot Websocket Mar 29 18:30:32 volumio go-librespot[18734]: time="2024-03-29T18:30:32+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 29 18:30:32 volumio volumio[891]: info: Connection to go-librespot Websocket established Mar 29 18:30:32 volumio go-librespot[18734]: time="2024-03-29T18:30:32+03:00" level=debug msg="new websocket client" Mar 29 18:30:32 volumio volumio[891]: info: CoreCommandRouter::volumioGetState Mar 29 18:30:32 volumio volumio[891]: info: CorePlayQueue::getTrack 0 Mar 29 18:30:32 volumio volumio[891]: info: Listing playlists Mar 29 18:30:32 volumio volumio[891]: info: Listing playlists Mar 29 18:30:32 volumio go-librespot[18734]: time="2024-03-29T18:30:32+03:00" level=debug msg="completed keyexchange" Mar 29 18:30:33 volumio go-librespot[18734]: time="2024-03-29T18:30:33+03:00" level=debug msg="completed challenge" Mar 29 18:30:33 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:33 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:33 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:33 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:33 volumio go-librespot[18734]: time="2024-03-29T18:30:33+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 29 18:30:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 29 18:30:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 29 18:30:33 volumio volumio[891]: info: Connection to go-librespot Websocket closed Mar 29 18:30:34 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:34 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:34 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:34 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:35 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:35 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:35 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:35 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:35 volumio volumio[891]: info: Getting Spotify volume Mar 29 18:30:35 volumio volumio[891]: (node:891) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 18:30:35 volumio volumio[891]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 29 18:30:35 volumio volumio[891]: (node:891) 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: 1547) Mar 29 18:30:35 volumio volumio[891]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 6 Mar 29 18:30:35 volumio volumio[891]: info: CoreCommandRouter::volumioGetState Mar 29 18:30:35 volumio volumio[891]: info: CorePlayQueue::getTrack 0 Mar 29 18:30:36 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:36 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:36 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:36 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:36 volumio volumio[891]: info: Initializing connection to go-librespot Websocket Mar 29 18:30:36 volumio volumio[891]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 18:30:36 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 29 18:30:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4437. Mar 29 18:30:36 volumio systemd[1]: Stopped go-librespot Daemon. Mar 29 18:30:36 volumio systemd[1]: Started go-librespot Daemon. Mar 29 18:30:36 volumio go-librespot[18750]: Librespot-go daemon starting... Mar 29 18:30:36 volumio go-librespot[18750]: time="2024-03-29T18:30:36+03:00" level=info msg="generated new device id: e6bd887d3676dfd4dbedc6ce201d0b39a13687eb" Mar 29 18:30:36 volumio go-librespot[18750]: time="2024-03-29T18:30:36+03:00" level=debug msg="stored credentials found for 31szglwegdhn6gw7vu4wo4rv33ya" Mar 29 18:30:36 volumio go-librespot[18750]: time="2024-03-29T18:30:36+03:00" level=debug msg="obtained new client token: AABuy4eE12QYNtJF+aQcMBZfozB2i8PinpSAbmLKzWCYv4nOT6r6ywvOC8BagPL1f1qVVvTvW7YVhs7UQ4UbeCzIqVT8zkQB9753LDCE46CpFfbPeh43mnFokGzikgmHEJ1rz/DBUZHXzCXCUncBkXyYn48muXdxxUuJpGYFzbMHgAicyJdM4wO+Ea12u7QqDWWeGFd888B+/pXqR2f81iE/uC9RlOg86a8juM2xmBqT5zGyiC3lo9wAw2eu" Mar 29 18:30:36 volumio go-librespot[18750]: time="2024-03-29T18:30:36+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 29 18:30:37 volumio go-librespot[18750]: time="2024-03-29T18:30:37+03:00" level=debug msg="completed keyexchange" Mar 29 18:30:37 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:37 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:37 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:37 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:37 volumio go-librespot[18750]: time="2024-03-29T18:30:37+03:00" level=debug msg="completed challenge" Mar 29 18:30:37 volumio go-librespot[18750]: time="2024-03-29T18:30:37+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 29 18:30:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 29 18:30:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 29 18:30:38 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:38 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:38 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:38 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:39 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:39 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:39 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:39 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:39 volumio volumio[891]: info: Initializing connection to go-librespot Websocket Mar 29 18:30:39 volumio volumio[891]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 18:30:40 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:40 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:40 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:40 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:40 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 29 18:30:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4438. Mar 29 18:30:40 volumio systemd[1]: Stopped go-librespot Daemon. Mar 29 18:30:40 volumio systemd[1]: Started go-librespot Daemon. Mar 29 18:30:40 volumio go-librespot[18766]: Librespot-go daemon starting... Mar 29 18:30:40 volumio go-librespot[18766]: time="2024-03-29T18:30:40+03:00" level=info msg="generated new device id: a06c94e18a03a95b8c0840955eb79ac1352661e2" Mar 29 18:30:40 volumio go-librespot[18766]: time="2024-03-29T18:30:40+03:00" level=debug msg="stored credentials found for 31szglwegdhn6gw7vu4wo4rv33ya" Mar 29 18:30:41 volumio go-librespot[18766]: time="2024-03-29T18:30:41+03:00" level=debug msg="obtained new client token: AAC3hYBT+/va0fs3+j4u+djA/qxET3AUHNxZKX7xZtg7eCMfmR9tk3lmG8i3GxulQmcCq7MDo5WQZ5MU56Kq3eBIj7aCbbm8jVgjtR9E4/DRVEycy2Ln9NX24znxQP1v6+Km71MykyJij9wL9l3Wj9zIPkw6UUVArZ6alBWmEu90lv3Sey/CtnwgmNzKfJteGNjylQ/MD9DE4CqZ6NFulcOToAA79QsIS+vk5kNWB+BKBKiJCcblbo4hnw==" Mar 29 18:30:41 volumio go-librespot[18766]: time="2024-03-29T18:30:41+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 29 18:30:41 volumio go-librespot[18766]: time="2024-03-29T18:30:41+03:00" level=debug msg="completed keyexchange" Mar 29 18:30:41 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:41 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:41 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:41 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:41 volumio go-librespot[18766]: time="2024-03-29T18:30:41+03:00" level=debug msg="completed challenge" Mar 29 18:30:41 volumio go-librespot[18766]: time="2024-03-29T18:30:41+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 29 18:30:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 29 18:30:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 29 18:30:42 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:42 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:42 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:42 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:42 volumio volumio[891]: info: Initializing connection to go-librespot Websocket Mar 29 18:30:42 volumio volumio[891]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 29 18:30:42 volumio volumio[891]: info: CoreCommandRouter::volumioGetState Mar 29 18:30:42 volumio volumio[891]: info: CorePlayQueue::getTrack 0 Mar 29 18:30:43 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:43 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:43 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:43 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:44 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:44 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:44 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:44 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:45 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 29 18:30:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4439. Mar 29 18:30:45 volumio systemd[1]: Stopped go-librespot Daemon. Mar 29 18:30:45 volumio systemd[1]: Started go-librespot Daemon. Mar 29 18:30:45 volumio go-librespot[18785]: Librespot-go daemon starting... Mar 29 18:30:45 volumio go-librespot[18785]: time="2024-03-29T18:30:45+03:00" level=info msg="generated new device id: 7c9d961fa90896b40f8d1838be8c3aed4f1d0f1e" Mar 29 18:30:45 volumio go-librespot[18785]: time="2024-03-29T18:30:45+03:00" level=debug msg="stored credentials found for 31szglwegdhn6gw7vu4wo4rv33ya" Mar 29 18:30:45 volumio go-librespot[18785]: time="2024-03-29T18:30:45+03:00" level=debug msg="obtained new client token: AAArfsTP2VpVP6lplcrz/Dm6LDRWpCmWebvdnU/YhUXZ9N/XlVPFjrvK2Tb99YjyDZkFIuqwdQ8oDKqtOT9AqiUjID5R5XMggkdCPcKb0xHTR7MWMFCs1QdQtEztLbQiBm98FDnxFU5GK4AkrfTFM/TbVI/fUH7ArKEsNlVgcwec5vfNigisIKMnzVURs9u39Gmc5qx67VADF9cUXrKxD56vl+fK0x377R6Edm+0EDf0H0aJn5xUe5HA1gRU" Mar 29 18:30:45 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:45 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:45 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:45 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:45 volumio go-librespot[18785]: time="2024-03-29T18:30:45+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Mar 29 18:30:45 volumio volumio[891]: info: Initializing connection to go-librespot Websocket Mar 29 18:30:45 volumio volumio[891]: info: Connection to go-librespot Websocket established Mar 29 18:30:45 volumio go-librespot[18785]: time="2024-03-29T18:30:45+03:00" level=debug msg="new websocket client" Mar 29 18:30:46 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:46 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:46 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:46 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:47 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:47 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:47 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:47 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:48 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:48 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:48 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:48 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:48 volumio volumio[891]: info: Getting Spotify volume Mar 29 18:30:48 volumio volumio[891]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 6 Mar 29 18:30:48 volumio volumio[891]: info: CoreCommandRouter::volumioGetState Mar 29 18:30:48 volumio volumio[891]: info: CorePlayQueue::getTrack 0 Mar 29 18:30:49 volumio lircd[677]: lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:49 volumio lircd[677]: lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:49 volumio lircd-0.10.1[677]: Error: could not get file information for /dev/lirc/0 Mar 29 18:30:49 volumio lircd-0.10.1[677]: default_init(): No such file or directory Mar 29 18:30:50 volumio volumio[891]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 29 18:30:50 volumio volumio[891]: Error: connect ETIMEDOUT 151.101.38.79:80 Mar 29 18:30:50 volumio volumio[891]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) { Mar 29 18:30:50 volumio volumio[891]: errno: -110, Mar 29 18:30:50 volumio volumio[891]: code: 'ETIMEDOUT', Mar 29 18:30:50 volumio volumio[891]: syscall: 'connect', Mar 29 18:30:50 volumio volumio[891]: address: '151.101.38.79', Mar 29 18:30:50 volumio volumio[891]: port: 80 Mar 29 18:30:50 volumio volumio[891]: } Mar 29 18:30:50 volumio volumio[891]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 29 18:30:50 volumio sudo[18810]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-03-29 18:29 Mar 29 18:30:50 volumio sudo[18810]: 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"