-- Logs begin at Wed 2024-04-24 07:24:36 AEST, end at Wed 2024-04-24 09:56:54 AEST. -- Apr 24 09:55:00 digimusic go-librespot[24417]: time="2024-04-24T09:55:00+10:00" level=debug msg="completed keyexchange" Apr 24 09:55:00 digimusic go-librespot[24417]: time="2024-04-24T09:55:00+10:00" level=debug msg="completed challenge" Apr 24 09:55:00 digimusic go-librespot[24417]: time="2024-04-24T09:55:00+10:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 24 09:55:00 digimusic systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 24 09:55:00 digimusic systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 24 09:55:02 digimusic volumio[834]: info: Initializing connection to go-librespot Websocket Apr 24 09:55:02 digimusic volumio[834]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 24 09:55:04 digimusic systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 24 09:55:04 digimusic systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38199. Apr 24 09:55:04 digimusic systemd[1]: Stopped go-librespot Daemon. Apr 24 09:55:04 digimusic systemd[1]: Started go-librespot Daemon. Apr 24 09:55:04 digimusic go-librespot[24425]: Librespot-go daemon starting... Apr 24 09:55:04 digimusic go-librespot[24425]: time="2024-04-24T09:55:04+10:00" level=info msg="generated new device id: 6b47e835e077b136fd6b0f6ee51e2eec6863f686" Apr 24 09:55:04 digimusic go-librespot[24425]: time="2024-04-24T09:55:04+10:00" level=debug msg="stored credentials found for drhonk" Apr 24 09:55:04 digimusic go-librespot[24425]: time="2024-04-24T09:55:04+10:00" level=debug msg="obtained new client token: AADva+eBkhjEaUaKmjxLmTEIv222QeV/uwb5vCY4CzB/fO9bApbQgLiSMl/BrotBE/Jq6ExKOJPFLAp8Hd4FmiMAo7AirGcKWLLG4gu3M9ZkB3T6e+QMYADE1GaNmPtei467mkGv3jFRHye7PKI7FGY8y7Ul22XNgzgPy28HAjCE5y48fD6aqKZ37q/6kCxF1bsEEB7Eyz+AETTQgAYHyvYTPxCKIBS6xDAIoJ7aUV0N6P4wWykzU7d0d94TG3A=" Apr 24 09:55:04 digimusic go-librespot[24425]: time="2024-04-24T09:55:04+10:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 24 09:55:05 digimusic go-librespot[24425]: time="2024-04-24T09:55:05+10:00" level=debug msg="completed keyexchange" Apr 24 09:55:05 digimusic volumio[834]: info: Initializing connection to go-librespot Websocket Apr 24 09:55:05 digimusic go-librespot[24425]: time="2024-04-24T09:55:05+10:00" level=debug msg="new websocket client" Apr 24 09:55:05 digimusic volumio[834]: info: Connection to go-librespot Websocket established Apr 24 09:55:05 digimusic go-librespot[24425]: time="2024-04-24T09:55:05+10:00" level=debug msg="completed challenge" Apr 24 09:55:05 digimusic go-librespot[24425]: time="2024-04-24T09:55:05+10:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 24 09:55:05 digimusic systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 24 09:55:05 digimusic systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 24 09:55:05 digimusic volumio[834]: info: Connection to go-librespot Websocket closed Apr 24 09:55:08 digimusic volumio[834]: info: Getting Spotify volume Apr 24 09:55:08 digimusic volumio[834]: (node:834) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 24 09:55:08 digimusic volumio[834]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 24 09:55:08 digimusic volumio[834]: (node:834) 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: 20255) Apr 24 09:55:08 digimusic volumio[834]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Apr 24 09:55:08 digimusic volumio[834]: info: CoreCommandRouter::volumioGetState Apr 24 09:55:08 digimusic volumio[834]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 09:55:08 digimusic volumio[834]: info: Initializing connection to go-librespot Websocket Apr 24 09:55:08 digimusic volumio[834]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 24 09:55:08 digimusic systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 24 09:55:08 digimusic systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38200. Apr 24 09:55:08 digimusic systemd[1]: Stopped go-librespot Daemon. Apr 24 09:55:08 digimusic systemd[1]: Started go-librespot Daemon. Apr 24 09:55:08 digimusic go-librespot[24433]: Librespot-go daemon starting... Apr 24 09:55:08 digimusic go-librespot[24433]: time="2024-04-24T09:55:08+10:00" level=info msg="generated new device id: 8ff518cf5c7ade354970f6e505af9e77ef1c1198" Apr 24 09:55:08 digimusic go-librespot[24433]: time="2024-04-24T09:55:08+10:00" level=debug msg="stored credentials found for drhonk" Apr 24 09:55:09 digimusic go-librespot[24433]: time="2024-04-24T09:55:09+10:00" level=debug msg="obtained new client token: AAAurhFNrrjEjOJIxnVXIFb8fsFhsxNbUnaez81ODLUnqPbJ0EnJCaqenwa+PmzBCAJfz25WHJhqFOGTLXRJzPiq4MGD3DVS0L4uLZ484bLo7N4KqW3dZMUvGXY5kHoHjOQW0JFpuexu2JebPEaZ2ldipSILYYbat2pwMjv7PEb0kBdK9aBh/XNuHBkjS6N8+OtAtE9BV1L7qbEA/luLFRMq/p1e3dfQb19GWnlZ+jC0RbRX7W0bGXx4aGth" Apr 24 09:55:09 digimusic go-librespot[24433]: time="2024-04-24T09:55:09+10:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 24 09:55:09 digimusic go-librespot[24433]: time="2024-04-24T09:55:09+10:00" level=debug msg="completed keyexchange" Apr 24 09:55:10 digimusic go-librespot[24433]: time="2024-04-24T09:55:10+10:00" level=debug msg="completed challenge" Apr 24 09:55:10 digimusic go-librespot[24433]: time="2024-04-24T09:55:10+10:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 24 09:55:10 digimusic systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 24 09:55:10 digimusic systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 24 09:55:11 digimusic volumio[834]: info: Initializing connection to go-librespot Websocket Apr 24 09:55:11 digimusic volumio[834]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 24 09:55:13 digimusic systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 24 09:55:13 digimusic systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38201. Apr 24 09:55:13 digimusic systemd[1]: Stopped go-librespot Daemon. Apr 24 09:55:13 digimusic systemd[1]: Started go-librespot Daemon. Apr 24 09:55:13 digimusic go-librespot[24441]: Librespot-go daemon starting... Apr 24 09:55:13 digimusic go-librespot[24441]: time="2024-04-24T09:55:13+10:00" level=info msg="generated new device id: 1d95baf0bf7d285aa382a5ec8704c96b046d7557" Apr 24 09:55:13 digimusic go-librespot[24441]: time="2024-04-24T09:55:13+10:00" level=debug msg="stored credentials found for drhonk" Apr 24 09:55:13 digimusic go-librespot[24441]: time="2024-04-24T09:55:13+10:00" level=debug msg="obtained new client token: AADTapSdbTBjqft0wJ12/JBLHLyn2WaSMes5cmvlMoUsxc4CN8XloRkpwYvSVttYKCiP13VhEA0KEqrUqfMwk0LD4gsJCwYUxErQbDLvq7Alu1KdXyPYOcPI8n9WIzdmag3LCDGrHuOsuhWnsw9br/qKa3nGFQNH0bGVnLfEQy85WxD7uHznuMdOSbxF+zH1ToI3k9D/PSFDULmtoxRnbBpzSqOGqdC/YnAZVk530c0ihh0Wd1YfD8Rryxc92u0=" Apr 24 09:55:14 digimusic go-librespot[24441]: time="2024-04-24T09:55:14+10:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 24 09:55:14 digimusic go-librespot[24441]: time="2024-04-24T09:55:14+10:00" level=debug msg="completed keyexchange" Apr 24 09:55:14 digimusic volumio[834]: info: Initializing connection to go-librespot Websocket Apr 24 09:55:14 digimusic go-librespot[24441]: time="2024-04-24T09:55:14+10:00" level=debug msg="new websocket client" Apr 24 09:55:14 digimusic volumio[834]: info: Connection to go-librespot Websocket established Apr 24 09:55:15 digimusic go-librespot[24441]: time="2024-04-24T09:55:15+10:00" level=debug msg="completed challenge" Apr 24 09:55:15 digimusic go-librespot[24441]: time="2024-04-24T09:55:15+10:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 24 09:55:15 digimusic systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 24 09:55:15 digimusic systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 24 09:55:15 digimusic volumio[834]: info: Connection to go-librespot Websocket closed Apr 24 09:55:17 digimusic volumio[834]: info: Getting Spotify volume Apr 24 09:55:17 digimusic volumio[834]: (node:834) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 24 09:55:17 digimusic volumio[834]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 24 09:55:17 digimusic volumio[834]: (node:834) 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: 20256) Apr 24 09:55:17 digimusic volumio[834]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Apr 24 09:55:17 digimusic volumio[834]: info: CoreCommandRouter::volumioGetState Apr 24 09:55:17 digimusic volumio[834]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 09:55:18 digimusic volumio[834]: info: Initializing connection to go-librespot Websocket Apr 24 09:55:18 digimusic volumio[834]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 24 09:55:18 digimusic systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 24 09:55:18 digimusic systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38202. Apr 24 09:55:18 digimusic systemd[1]: Stopped go-librespot Daemon. Apr 24 09:55:18 digimusic systemd[1]: Started go-librespot Daemon. Apr 24 09:55:18 digimusic go-librespot[24449]: Librespot-go daemon starting... Apr 24 09:55:18 digimusic go-librespot[24449]: time="2024-04-24T09:55:18+10:00" level=info msg="generated new device id: 0ae51a56da68c3122eba9f7912bfbb81690ba077" Apr 24 09:55:18 digimusic go-librespot[24449]: time="2024-04-24T09:55:18+10:00" level=debug msg="stored credentials found for drhonk" Apr 24 09:55:18 digimusic go-librespot[24449]: time="2024-04-24T09:55:18+10:00" level=debug msg="obtained new client token: AAAtajyI9xfcjFXx2ZDdNtsoJsPogja/vsc3kC2ZjaOcWEb/oM/UoHCEDTS42DwzBFKKn3d3NMMG3ScgtibXZHaeR84Es4gWBZjjw8+dY/ofVXRrnfgpHcj3xPXFYf6NXRGTPWXDeZ6xRWhQGPBfiVm632Dw+c/L/Rxpb+CBYpVjSd0YjV6j+0w7X0Fo/HvfLbIB0nHMc+StNogBm69mJPFmqi9HpOpw+76uq+lWTUarYoH3YrVFIYE4yT+dIpc=" Apr 24 09:55:18 digimusic go-librespot[24449]: time="2024-04-24T09:55:18+10:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 24 09:55:19 digimusic go-librespot[24449]: time="2024-04-24T09:55:19+10:00" level=debug msg="completed keyexchange" Apr 24 09:55:19 digimusic go-librespot[24449]: time="2024-04-24T09:55:19+10:00" level=debug msg="completed challenge" Apr 24 09:55:19 digimusic go-librespot[24449]: time="2024-04-24T09:55:19+10:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 24 09:55:19 digimusic systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 24 09:55:19 digimusic systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 24 09:55:21 digimusic volumio[834]: info: Initializing connection to go-librespot Websocket Apr 24 09:55:21 digimusic volumio[834]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 24 09:55:23 digimusic systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 24 09:55:23 digimusic systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38203. Apr 24 09:55:23 digimusic systemd[1]: Stopped go-librespot Daemon. Apr 24 09:55:23 digimusic systemd[1]: Started go-librespot Daemon. Apr 24 09:55:23 digimusic go-librespot[24458]: Librespot-go daemon starting... Apr 24 09:55:23 digimusic go-librespot[24458]: time="2024-04-24T09:55:23+10:00" level=info msg="generated new device id: d01ba7db7a58101909d0f85041910593a78b7b6e" Apr 24 09:55:23 digimusic go-librespot[24458]: time="2024-04-24T09:55:23+10:00" level=debug msg="stored credentials found for drhonk" Apr 24 09:55:23 digimusic go-librespot[24458]: time="2024-04-24T09:55:23+10:00" level=debug msg="obtained new client token: AAACDjRXJ+JwrXBbMZQ1KUJ/moeMbYkwXEYnSvdT1VU4fubH/huUPquMLS4SG4D+OBP27+Vethwj8rll/Y7kzcHBoDRkp20RplNdnrHpVjcUsBm5+JsrKaw1RYVkE8PPUGIlbM22okwJQM7S1HQPj+dFZhtcebVVcT1IJwiQBUA+gMHNT7DqIDkRaDGkbjUzb1Ryqf7dZf+7tbqhhf8dOmV+zppMVv8JRsGREG2NdhcEhvlBz9rLD1+XHqLGVXo=" Apr 24 09:55:23 digimusic go-librespot[24458]: time="2024-04-24T09:55:23+10:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Apr 24 09:55:24 digimusic go-librespot[24458]: time="2024-04-24T09:55:24+10:00" level=debug msg="completed keyexchange" Apr 24 09:55:24 digimusic volumio[834]: info: Initializing connection to go-librespot Websocket Apr 24 09:55:24 digimusic go-librespot[24458]: time="2024-04-24T09:55:24+10:00" level=debug msg="new websocket client" Apr 24 09:55:24 digimusic volumio[834]: info: Connection to go-librespot Websocket established Apr 24 09:55:24 digimusic go-librespot[24458]: time="2024-04-24T09:55:24+10:00" level=debug msg="completed challenge" Apr 24 09:55:24 digimusic go-librespot[24458]: time="2024-04-24T09:55:24+10:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 24 09:55:24 digimusic systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 24 09:55:24 digimusic systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 24 09:55:24 digimusic volumio[834]: info: Connection to go-librespot Websocket closed Apr 24 09:55:27 digimusic volumio[834]: info: Getting Spotify volume Apr 24 09:55:27 digimusic volumio[834]: (node:834) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 24 09:55:27 digimusic volumio[834]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 24 09:55:27 digimusic volumio[834]: (node:834) 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: 20257) Apr 24 09:55:27 digimusic volumio[834]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Apr 24 09:55:27 digimusic volumio[834]: info: CoreCommandRouter::volumioGetState Apr 24 09:55:27 digimusic volumio[834]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 09:55:27 digimusic volumio[834]: info: Initializing connection to go-librespot Websocket Apr 24 09:55:27 digimusic volumio[834]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 24 09:55:27 digimusic systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 24 09:55:27 digimusic systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38204. Apr 24 09:55:27 digimusic systemd[1]: Stopped go-librespot Daemon. Apr 24 09:55:27 digimusic systemd[1]: Started go-librespot Daemon. Apr 24 09:55:27 digimusic go-librespot[24466]: Librespot-go daemon starting... Apr 24 09:55:27 digimusic go-librespot[24466]: time="2024-04-24T09:55:27+10:00" level=info msg="generated new device id: 869914c40d349b269fe768484218cad6c6a818b1" Apr 24 09:55:27 digimusic go-librespot[24466]: time="2024-04-24T09:55:27+10:00" level=debug msg="stored credentials found for drhonk" Apr 24 09:55:28 digimusic go-librespot[24466]: time="2024-04-24T09:55:28+10:00" level=debug msg="obtained new client token: AACXO0odggLqJkVYMDx/q8iqadmWqzUkznm3GE1BqgnrLhOha603tO+z1PEuXml7+XYjZfadqQvSoedIUsrVK2HXUalyxESdplysXF0rdrGlmQouMk/2NpMQpxJVGTkSy+Vj0PoicbmRUCJ60X7mbYOt6P5k1QVzuTfQxrWeRfhUGuTIF5b7dn6iAAutJ6uqwM32L9/X9b0ewkjrM5CRo2pHg47UCbX+JwZvnGLxftF+QOTNpMq46Ah094iw" Apr 24 09:55:28 digimusic go-librespot[24466]: time="2024-04-24T09:55:28+10:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 24 09:55:28 digimusic go-librespot[24466]: time="2024-04-24T09:55:28+10:00" level=debug msg="completed keyexchange" Apr 24 09:55:29 digimusic go-librespot[24466]: time="2024-04-24T09:55:29+10:00" level=debug msg="completed challenge" Apr 24 09:55:29 digimusic go-librespot[24466]: time="2024-04-24T09:55:29+10:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 24 09:55:29 digimusic systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 24 09:55:29 digimusic systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 24 09:55:30 digimusic volumio[834]: info: Initializing connection to go-librespot Websocket Apr 24 09:55:30 digimusic volumio[834]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 24 09:55:32 digimusic systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 24 09:55:32 digimusic systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38205. Apr 24 09:55:32 digimusic systemd[1]: Stopped go-librespot Daemon. Apr 24 09:55:32 digimusic systemd[1]: Started go-librespot Daemon. Apr 24 09:55:32 digimusic go-librespot[24533]: Librespot-go daemon starting... Apr 24 09:55:32 digimusic go-librespot[24533]: time="2024-04-24T09:55:32+10:00" level=info msg="generated new device id: a81a6f3f33e565635a54434331680f1aeba1c478" Apr 24 09:55:32 digimusic go-librespot[24533]: time="2024-04-24T09:55:32+10:00" level=debug msg="stored credentials found for drhonk" Apr 24 09:55:32 digimusic go-librespot[24533]: time="2024-04-24T09:55:32+10:00" level=debug msg="obtained new client token: AADCCe3N27dukmEktJHFQy9l8xJOJmHOTTJeEf7wSMibxYgHDygQcY92rRlvIcd8g0qbm0XhVNj81LL3w5q+4qULRiRLKDpIeYIUX1MqybhLGL1h2bKMv7op/Auv/ITvm/urSVpylJOFo2L1gouannRxnWVP/2KFobNgudI2eUdtEe1mRjVnpQe8ygyp+qGmaP5AafoS3rGnlzcOIhtJL+6kEVBuAtnkPFZ6nK+7gbyHJW4nfcQIdJyNOAFHw+Q=" Apr 24 09:55:33 digimusic go-librespot[24533]: time="2024-04-24T09:55:33+10:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Apr 24 09:55:33 digimusic go-librespot[24533]: time="2024-04-24T09:55:33+10:00" level=debug msg="completed keyexchange" Apr 24 09:55:33 digimusic volumio[834]: info: Initializing connection to go-librespot Websocket Apr 24 09:55:33 digimusic volumio[834]: info: Connection to go-librespot Websocket established Apr 24 09:55:33 digimusic go-librespot[24533]: time="2024-04-24T09:55:33+10:00" level=debug msg="new websocket client" Apr 24 09:55:33 digimusic go-librespot[24533]: time="2024-04-24T09:55:33+10:00" level=debug msg="completed challenge" Apr 24 09:55:34 digimusic go-librespot[24533]: time="2024-04-24T09:55:34+10:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 24 09:55:34 digimusic systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 24 09:55:34 digimusic systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 24 09:55:34 digimusic volumio[834]: info: Connection to go-librespot Websocket closed Apr 24 09:55:36 digimusic volumio[834]: info: Getting Spotify volume Apr 24 09:55:36 digimusic volumio[834]: (node:834) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 24 09:55:36 digimusic volumio[834]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 24 09:55:36 digimusic volumio[834]: (node:834) 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: 20258) Apr 24 09:55:36 digimusic volumio[834]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Apr 24 09:55:36 digimusic volumio[834]: info: CoreCommandRouter::volumioGetState Apr 24 09:55:36 digimusic volumio[834]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 09:55:37 digimusic volumio[834]: info: Initializing connection to go-librespot Websocket Apr 24 09:55:37 digimusic volumio[834]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 24 09:55:37 digimusic systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 24 09:55:37 digimusic systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38206. Apr 24 09:55:37 digimusic systemd[1]: Stopped go-librespot Daemon. Apr 24 09:55:37 digimusic systemd[1]: Started go-librespot Daemon. Apr 24 09:55:37 digimusic go-librespot[24541]: Librespot-go daemon starting... Apr 24 09:55:37 digimusic go-librespot[24541]: time="2024-04-24T09:55:37+10:00" level=info msg="generated new device id: c72adc96b1912e5c675f7309b5c0991c28460be2" Apr 24 09:55:37 digimusic go-librespot[24541]: time="2024-04-24T09:55:37+10:00" level=debug msg="stored credentials found for drhonk" Apr 24 09:55:37 digimusic go-librespot[24541]: time="2024-04-24T09:55:37+10:00" level=debug msg="obtained new client token: AAACtoY3tRO5nim/noHkbaeVJ6Pv9JyXM12qeoeGwU55DgYhndFDOU3qOGAQWhACYCULY2U6FJsJmUMBM4vYIHX85s6EQfQbAVqsab/0DDzWETXYBztsMUo/uzCxOL8FNyX5vM8qRmvzp3I2a51tuyScmQsv4VilwqtrhRHMYguGnO7yDov4madhN1qEfzg7e7k5uxhp2YclN2l26WCryrw5sCfi1OHKNaW5fY8U080LULLgoYKKHPzlvs76pr4=" Apr 24 09:55:37 digimusic go-librespot[24541]: time="2024-04-24T09:55:37+10:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 24 09:55:38 digimusic go-librespot[24541]: time="2024-04-24T09:55:38+10:00" level=debug msg="completed keyexchange" Apr 24 09:55:38 digimusic go-librespot[24541]: time="2024-04-24T09:55:38+10:00" level=debug msg="completed challenge" Apr 24 09:55:38 digimusic go-librespot[24541]: time="2024-04-24T09:55:38+10:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 24 09:55:38 digimusic systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 24 09:55:38 digimusic systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 24 09:55:40 digimusic volumio[834]: info: Initializing connection to go-librespot Websocket Apr 24 09:55:40 digimusic volumio[834]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 24 09:55:42 digimusic systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 24 09:55:42 digimusic systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38207. Apr 24 09:55:42 digimusic systemd[1]: Stopped go-librespot Daemon. Apr 24 09:55:42 digimusic systemd[1]: Started go-librespot Daemon. Apr 24 09:55:42 digimusic go-librespot[24551]: Librespot-go daemon starting... Apr 24 09:55:42 digimusic go-librespot[24551]: time="2024-04-24T09:55:42+10:00" level=info msg="generated new device id: 18a3b0878a2ff27ad8775adc5b3952b86e996b8c" Apr 24 09:55:42 digimusic go-librespot[24551]: time="2024-04-24T09:55:42+10:00" level=debug msg="stored credentials found for drhonk" Apr 24 09:55:42 digimusic go-librespot[24551]: time="2024-04-24T09:55:42+10:00" level=debug msg="obtained new client token: AADMRlfaOAFipP3Hw5YKz6AecKzQvwtXJXJZvgY/2CbGSGOXr/bs4V7eDdMkf+fGLwdZM4l8U/uxCXPq8RZ6/+tf7i3K6aT9JbJ5uHn+lzTwoN37IDJJozJuEFfwahWaGZUlkTjtDregia+ssJAGmaloAN22c/tjXXz5AVKItonNKo/+PDOC671w65NqSL1s+pJOuezHqcXSYoOmLztrW523v2L8U7N21uW1LoOgXvYm5uacs4PLcWvvfYIFfuc=" Apr 24 09:55:42 digimusic go-librespot[24551]: time="2024-04-24T09:55:42+10:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 24 09:55:42 digimusic go-librespot[24551]: time="2024-04-24T09:55:42+10:00" level=debug msg="completed keyexchange" Apr 24 09:55:43 digimusic volumio[834]: info: Initializing connection to go-librespot Websocket Apr 24 09:55:43 digimusic go-librespot[24551]: time="2024-04-24T09:55:43+10:00" level=debug msg="new websocket client" Apr 24 09:55:43 digimusic volumio[834]: info: Connection to go-librespot Websocket established Apr 24 09:55:43 digimusic go-librespot[24551]: time="2024-04-24T09:55:43+10:00" level=debug msg="completed challenge" Apr 24 09:55:43 digimusic go-librespot[24551]: time="2024-04-24T09:55:43+10:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 24 09:55:43 digimusic volumio[834]: info: Connection to go-librespot Websocket closed Apr 24 09:55:43 digimusic systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 24 09:55:43 digimusic systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 24 09:55:46 digimusic volumio[834]: info: Getting Spotify volume Apr 24 09:55:46 digimusic volumio[834]: (node:834) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 24 09:55:46 digimusic volumio[834]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 24 09:55:46 digimusic volumio[834]: (node:834) 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: 20259) Apr 24 09:55:46 digimusic volumio[834]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Apr 24 09:55:46 digimusic volumio[834]: info: CoreCommandRouter::volumioGetState Apr 24 09:55:46 digimusic volumio[834]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 09:55:46 digimusic volumio[834]: info: Initializing connection to go-librespot Websocket Apr 24 09:55:46 digimusic volumio[834]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 24 09:55:46 digimusic systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 24 09:55:46 digimusic systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38208. Apr 24 09:55:46 digimusic systemd[1]: Stopped go-librespot Daemon. Apr 24 09:55:46 digimusic systemd[1]: Started go-librespot Daemon. Apr 24 09:55:46 digimusic go-librespot[24560]: Librespot-go daemon starting... Apr 24 09:55:46 digimusic go-librespot[24560]: time="2024-04-24T09:55:46+10:00" level=info msg="generated new device id: 1e109dcd865db5ba5e7bcd9259aa5107aa4ae899" Apr 24 09:55:46 digimusic go-librespot[24560]: time="2024-04-24T09:55:46+10:00" level=debug msg="stored credentials found for drhonk" Apr 24 09:55:47 digimusic go-librespot[24560]: time="2024-04-24T09:55:47+10:00" level=debug msg="obtained new client token: AAAaTnYEgc0t9t/RQIW/mb3Er/853MzJS4Z6nliVQ9p73kft+2v66LLnz6us+sLSk+c/RiPi9BSlzeCqrTiwyTn8T976bN05yKu+OwDK798pRoZckW9SLHqdW3fnizm3jU1k1WT89sJk+Pjf6LvOGx8LKfWgE4hhsEKN5OdA26wu+VrpcPPPBG1OWR6lqoGnI85zE3EKofNmiN90vwpTpLDUIim0M8e19kDjlekJN3e5cNKdONarfcyd+2t6" Apr 24 09:55:47 digimusic go-librespot[24560]: time="2024-04-24T09:55:47+10:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 24 09:55:47 digimusic go-librespot[24560]: time="2024-04-24T09:55:47+10:00" level=debug msg="completed keyexchange" Apr 24 09:55:48 digimusic go-librespot[24560]: time="2024-04-24T09:55:48+10:00" level=debug msg="completed challenge" Apr 24 09:55:48 digimusic go-librespot[24560]: time="2024-04-24T09:55:48+10:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 24 09:55:48 digimusic systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 24 09:55:48 digimusic systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 24 09:55:49 digimusic volumio[834]: info: Initializing connection to go-librespot Websocket Apr 24 09:55:49 digimusic volumio[834]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 24 09:55:51 digimusic systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 24 09:55:51 digimusic systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38209. Apr 24 09:55:51 digimusic systemd[1]: Stopped go-librespot Daemon. Apr 24 09:55:51 digimusic systemd[1]: Started go-librespot Daemon. Apr 24 09:55:51 digimusic go-librespot[24568]: Librespot-go daemon starting... Apr 24 09:55:51 digimusic go-librespot[24568]: time="2024-04-24T09:55:51+10:00" level=info msg="generated new device id: c2027e9e9280cb0f13367325a8e89aba44e2f39d" Apr 24 09:55:51 digimusic go-librespot[24568]: time="2024-04-24T09:55:51+10:00" level=debug msg="stored credentials found for drhonk" Apr 24 09:55:51 digimusic go-librespot[24568]: time="2024-04-24T09:55:51+10:00" level=debug msg="obtained new client token: AAAvTpIV5KH3FayT/w6RZE9QqY1giD9E3Wa8StxqTU+kCBEMbsQlFz7OnqLiwplpEAFvCq7SOvgfUsAkffJyKNdM2cyzZqPz/hb77GriQkvTNURmv9g5cPsFvNkceLMNm4V7MZSryyei/7dafwNTClO9FtDtb9MTzz8tXaYN37MvMT5Oc66i8XUqOJzTD0FRpt842AGwrfRk8FNjBIdvGpET3jrlMy53OjFyn1lERPG5uZ5PC9LbN4BChr+f8nE=" Apr 24 09:55:52 digimusic go-librespot[24568]: time="2024-04-24T09:55:52+10:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Apr 24 09:55:52 digimusic go-librespot[24568]: time="2024-04-24T09:55:52+10:00" level=debug msg="completed keyexchange" Apr 24 09:55:52 digimusic volumio[834]: info: Initializing connection to go-librespot Websocket Apr 24 09:55:52 digimusic volumio[834]: info: Connection to go-librespot Websocket established Apr 24 09:55:52 digimusic go-librespot[24568]: time="2024-04-24T09:55:52+10:00" level=debug msg="new websocket client" Apr 24 09:55:53 digimusic go-librespot[24568]: time="2024-04-24T09:55:53+10:00" level=debug msg="completed challenge" Apr 24 09:55:53 digimusic go-librespot[24568]: time="2024-04-24T09:55:53+10:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 24 09:55:53 digimusic systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 24 09:55:53 digimusic systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 24 09:55:53 digimusic volumio[834]: info: Connection to go-librespot Websocket closed Apr 24 09:55:55 digimusic volumio[834]: info: Getting Spotify volume Apr 24 09:55:55 digimusic volumio[834]: (node:834) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 24 09:55:55 digimusic volumio[834]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 24 09:55:55 digimusic volumio[834]: (node:834) 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: 20260) Apr 24 09:55:55 digimusic volumio[834]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Apr 24 09:55:55 digimusic volumio[834]: info: CoreCommandRouter::volumioGetState Apr 24 09:55:55 digimusic volumio[834]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 09:55:56 digimusic volumio[834]: info: Initializing connection to go-librespot Websocket Apr 24 09:55:56 digimusic volumio[834]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 24 09:55:56 digimusic systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 24 09:55:56 digimusic systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38210. Apr 24 09:55:56 digimusic systemd[1]: Stopped go-librespot Daemon. Apr 24 09:55:56 digimusic systemd[1]: Started go-librespot Daemon. Apr 24 09:55:56 digimusic go-librespot[24576]: Librespot-go daemon starting... Apr 24 09:55:56 digimusic go-librespot[24576]: time="2024-04-24T09:55:56+10:00" level=info msg="generated new device id: 3e0c67d950f233e4cc0c2ed34f6c37c16d9ea0b1" Apr 24 09:55:56 digimusic go-librespot[24576]: time="2024-04-24T09:55:56+10:00" level=debug msg="stored credentials found for drhonk" Apr 24 09:55:56 digimusic go-librespot[24576]: time="2024-04-24T09:55:56+10:00" level=debug msg="obtained new client token: AACWSk1nIk9eh9WEOMCJQkH3u1uJKjFzZRQszaOvkx8niSpiSwoXSS0PkcjGCL6cxa0UhlHykCFuTWTVcg0yM8KslM8Cy4b/+bRMlyZc1HNhjc/g9UXz8Ie7lmRdjr/iIQScN6YwJSGwYUYYaLdWDaGA3iZKzz/fVPYlvNHeafaxyOnWUWPlBg1m3rSM+3nLV8XIg1F3pTNBQ4XqgYR2oO+7O3h78EXIDNFHAIQKs6WF37vg3/ZNUoDHpmsI1GM=" Apr 24 09:55:56 digimusic go-librespot[24576]: time="2024-04-24T09:55:56+10:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 24 09:55:57 digimusic go-librespot[24576]: time="2024-04-24T09:55:57+10:00" level=debug msg="completed keyexchange" Apr 24 09:55:57 digimusic go-librespot[24576]: time="2024-04-24T09:55:57+10:00" level=debug msg="completed challenge" Apr 24 09:55:57 digimusic go-librespot[24576]: time="2024-04-24T09:55:57+10:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 24 09:55:57 digimusic systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 24 09:55:57 digimusic systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 24 09:55:59 digimusic volumio[834]: info: Initializing connection to go-librespot Websocket Apr 24 09:55:59 digimusic volumio[834]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 24 09:56:01 digimusic systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 24 09:56:01 digimusic systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38211. Apr 24 09:56:01 digimusic systemd[1]: Stopped go-librespot Daemon. Apr 24 09:56:01 digimusic systemd[1]: Started go-librespot Daemon. Apr 24 09:56:01 digimusic go-librespot[24585]: Librespot-go daemon starting... Apr 24 09:56:01 digimusic go-librespot[24585]: time="2024-04-24T09:56:01+10:00" level=info msg="generated new device id: f1fdd18c0ca3e1796e0b81d8c45f7ae80f876a77" Apr 24 09:56:01 digimusic go-librespot[24585]: time="2024-04-24T09:56:01+10:00" level=debug msg="stored credentials found for drhonk" Apr 24 09:56:01 digimusic go-librespot[24585]: time="2024-04-24T09:56:01+10:00" level=debug msg="obtained new client token: AAB10cP61tSLTpPNYBQBvdiP+HCgCSVdSluWEdrCqRID5tUxnG+j/wuiI+1Xg/IjJA1SXsnhA9VMrXGnx+XKSHzZLYZQOQjjGaNhg5iBjIgimn4KNUSjp9f8ARb0mB+T6VrEfZtZlbTofJhrq/y25QzhCE+DOP3dYPN0tuUp5ozFt6RbrtRefmzyxU0ECocajbMD0WyrycwfnWG6/tRmD5eb/8AGxUOC9rD7M8XY/klMZbf/wStST3+HgklaV9A=" Apr 24 09:56:01 digimusic go-librespot[24585]: time="2024-04-24T09:56:01+10:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Apr 24 09:56:02 digimusic go-librespot[24585]: time="2024-04-24T09:56:02+10:00" level=debug msg="completed keyexchange" Apr 24 09:56:02 digimusic volumio[834]: info: Initializing connection to go-librespot Websocket Apr 24 09:56:02 digimusic go-librespot[24585]: time="2024-04-24T09:56:02+10:00" level=debug msg="new websocket client" Apr 24 09:56:02 digimusic volumio[834]: info: Connection to go-librespot Websocket established Apr 24 09:56:02 digimusic go-librespot[24585]: time="2024-04-24T09:56:02+10:00" level=debug msg="completed challenge" Apr 24 09:56:02 digimusic go-librespot[24585]: time="2024-04-24T09:56:02+10:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 24 09:56:02 digimusic systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 24 09:56:02 digimusic systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 24 09:56:02 digimusic volumio[834]: info: Connection to go-librespot Websocket closed Apr 24 09:56:05 digimusic volumio[834]: info: Getting Spotify volume Apr 24 09:56:05 digimusic volumio[834]: (node:834) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 24 09:56:05 digimusic volumio[834]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 24 09:56:05 digimusic volumio[834]: (node:834) 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: 20261) Apr 24 09:56:05 digimusic volumio[834]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Apr 24 09:56:05 digimusic volumio[834]: info: CoreCommandRouter::volumioGetState Apr 24 09:56:05 digimusic volumio[834]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 09:56:05 digimusic volumio[834]: info: Initializing connection to go-librespot Websocket Apr 24 09:56:05 digimusic volumio[834]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 24 09:56:05 digimusic systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 24 09:56:05 digimusic systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38212. Apr 24 09:56:05 digimusic systemd[1]: Stopped go-librespot Daemon. Apr 24 09:56:05 digimusic systemd[1]: Started go-librespot Daemon. Apr 24 09:56:05 digimusic go-librespot[24593]: Librespot-go daemon starting... Apr 24 09:56:05 digimusic go-librespot[24593]: time="2024-04-24T09:56:05+10:00" level=info msg="generated new device id: 5f0ddfc4f8f03b892cb8eb35753d6bb83e05f3a4" Apr 24 09:56:05 digimusic go-librespot[24593]: time="2024-04-24T09:56:05+10:00" level=debug msg="stored credentials found for drhonk" Apr 24 09:56:06 digimusic go-librespot[24593]: time="2024-04-24T09:56:06+10:00" level=debug msg="obtained new client token: AACcMGuOf9UH7owN+5LlX+Ns4A2X+OAfHOq7kjEcwopPbFzkSWLOxPI0RMbzMXVxi4RVuIinm/hRAEgGDjIEu/Qcz18slyGsXeV2LraeSdjDReJ7nXR2ThtWr2Bct+7nE+wZIYhUNDx+8vEqB3Q2UTY3Sime1c2wXAi+G9VGo4OJGltpPrnvnqXvH5Hfjx/ZmXOmQp+GIp8NjYu5CKyBpbunMzSnOW28eIZocvLt+RkKHjSCK0ZsvKemRCAC" Apr 24 09:56:06 digimusic go-librespot[24593]: time="2024-04-24T09:56:06+10:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 24 09:56:06 digimusic go-librespot[24593]: time="2024-04-24T09:56:06+10:00" level=debug msg="completed keyexchange" Apr 24 09:56:07 digimusic go-librespot[24593]: time="2024-04-24T09:56:07+10:00" level=debug msg="completed challenge" Apr 24 09:56:07 digimusic go-librespot[24593]: time="2024-04-24T09:56:07+10:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 24 09:56:07 digimusic systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 24 09:56:07 digimusic systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 24 09:56:08 digimusic volumio[834]: info: Initializing connection to go-librespot Websocket Apr 24 09:56:08 digimusic volumio[834]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 24 09:56:10 digimusic systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 24 09:56:10 digimusic systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38213. Apr 24 09:56:10 digimusic systemd[1]: Stopped go-librespot Daemon. Apr 24 09:56:10 digimusic systemd[1]: Started go-librespot Daemon. Apr 24 09:56:10 digimusic go-librespot[24602]: Librespot-go daemon starting... Apr 24 09:56:10 digimusic go-librespot[24602]: time="2024-04-24T09:56:10+10:00" level=info msg="generated new device id: bcfb4facd5c2d90e67c34c7c053415e7af05a9d3" Apr 24 09:56:10 digimusic go-librespot[24602]: time="2024-04-24T09:56:10+10:00" level=debug msg="stored credentials found for drhonk" Apr 24 09:56:10 digimusic go-librespot[24602]: time="2024-04-24T09:56:10+10:00" level=debug msg="obtained new client token: AABUa0C7oG6zf84rn5WHPKG+/S3kuNSCR0lYcrmHIQMMCuDT5SapQCkbQium4dEO9hM3GYdbo4KrYAMTK4S5CXGuUqu5X6/IYZTTyRX7Rd7IXsrK8oFiGAgo5ztfL9JkqSG2Drp3BnWLpQbNI66R1NCuEoIwfRETqs6+02gSBu32A+nKHkwhmTw6qP5HEphCweNcbuYO3ej08WoJzXbqymeBmVylLK8TKP6qyReKpIRElD5Crx4f5s8ffkT+L+o=" Apr 24 09:56:11 digimusic go-librespot[24602]: time="2024-04-24T09:56:11+10:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 24 09:56:11 digimusic go-librespot[24602]: time="2024-04-24T09:56:11+10:00" level=debug msg="completed keyexchange" Apr 24 09:56:11 digimusic volumio[834]: info: Initializing connection to go-librespot Websocket Apr 24 09:56:11 digimusic go-librespot[24602]: time="2024-04-24T09:56:11+10:00" level=debug msg="new websocket client" Apr 24 09:56:11 digimusic volumio[834]: info: Connection to go-librespot Websocket established Apr 24 09:56:11 digimusic go-librespot[24602]: time="2024-04-24T09:56:11+10:00" level=debug msg="completed challenge" Apr 24 09:56:12 digimusic go-librespot[24602]: time="2024-04-24T09:56:12+10:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 24 09:56:12 digimusic systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 24 09:56:12 digimusic systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 24 09:56:12 digimusic volumio[834]: info: Connection to go-librespot Websocket closed Apr 24 09:56:14 digimusic volumio[834]: info: Getting Spotify volume Apr 24 09:56:14 digimusic volumio[834]: (node:834) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 24 09:56:14 digimusic volumio[834]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 24 09:56:14 digimusic volumio[834]: (node:834) 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: 20262) Apr 24 09:56:14 digimusic volumio[834]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Apr 24 09:56:14 digimusic volumio[834]: info: CoreCommandRouter::volumioGetState Apr 24 09:56:14 digimusic volumio[834]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 09:56:15 digimusic volumio[834]: info: Initializing connection to go-librespot Websocket Apr 24 09:56:15 digimusic volumio[834]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 24 09:56:15 digimusic systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 24 09:56:15 digimusic systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38214. Apr 24 09:56:15 digimusic systemd[1]: Stopped go-librespot Daemon. Apr 24 09:56:15 digimusic systemd[1]: Started go-librespot Daemon. Apr 24 09:56:15 digimusic go-librespot[24611]: Librespot-go daemon starting... Apr 24 09:56:15 digimusic go-librespot[24611]: time="2024-04-24T09:56:15+10:00" level=info msg="generated new device id: c90e44dad482e11da0d076c8bcfdb802a72e17a8" Apr 24 09:56:15 digimusic go-librespot[24611]: time="2024-04-24T09:56:15+10:00" level=debug msg="stored credentials found for drhonk" Apr 24 09:56:15 digimusic go-librespot[24611]: time="2024-04-24T09:56:15+10:00" level=debug msg="obtained new client token: AADc/gf7ksR55mR6K9S0awCAoqFYvrFMg7hYlJoOylxb+/d0EMSJu6LOvpz0+fP3W0mFX8DxZGAH74z1gsy4QP6dHXJOs+F7xuLuB8ljShndyQKfknnRAjtm7E8HZmENLxgezrt1Bwzj9M/8vbIj2/Mcc9xk6tkIwTrxPpM08jzj8i8kvwsBwO44u+Lkh9HxIkiAksm+1lY0bwYtTRCSKBjBY/SK05TStRfAST+5mEDj5DnMyjx49NEGX/Dl9H8=" Apr 24 09:56:15 digimusic go-librespot[24611]: time="2024-04-24T09:56:15+10:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Apr 24 09:56:16 digimusic go-librespot[24611]: time="2024-04-24T09:56:16+10:00" level=debug msg="completed keyexchange" Apr 24 09:56:16 digimusic go-librespot[24611]: time="2024-04-24T09:56:16+10:00" level=debug msg="completed challenge" Apr 24 09:56:17 digimusic go-librespot[24611]: time="2024-04-24T09:56:17+10:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 24 09:56:17 digimusic systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 24 09:56:17 digimusic systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 24 09:56:18 digimusic volumio[834]: info: Initializing connection to go-librespot Websocket Apr 24 09:56:18 digimusic volumio[834]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 24 09:56:20 digimusic systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 24 09:56:20 digimusic systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38215. Apr 24 09:56:20 digimusic systemd[1]: Stopped go-librespot Daemon. Apr 24 09:56:20 digimusic systemd[1]: Started go-librespot Daemon. Apr 24 09:56:20 digimusic go-librespot[24619]: Librespot-go daemon starting... Apr 24 09:56:20 digimusic go-librespot[24619]: time="2024-04-24T09:56:20+10:00" level=info msg="generated new device id: 75d3d8c6abd3859f78f959e22784a531281ecbfd" Apr 24 09:56:20 digimusic go-librespot[24619]: time="2024-04-24T09:56:20+10:00" level=debug msg="stored credentials found for drhonk" Apr 24 09:56:20 digimusic go-librespot[24619]: time="2024-04-24T09:56:20+10:00" level=debug msg="obtained new client token: AAATOLM0IHOPwklB0IwoISsOAmEp2eMwzugcm1x8z3SunEhjPXFRszJyzuO+cBxYHp4Ubs06I5Lewnn0b5j0YoWPAjxHJxUi4oqGwoAqVgiCw0kA+30X0RzlwzKVdqbmREFOszEwxhwZOBKkEH6b8WljR4v1HpKBICab6a4ahSOkZteLQ1iy4q+gTwDPzJz5UO7GnnKezhCkBlXQE4mxexgyJPxGQjMnP2FivuWO/Duim67pWSM+jPARZSRhDbk=" Apr 24 09:56:20 digimusic go-librespot[24619]: time="2024-04-24T09:56:20+10:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 24 09:56:20 digimusic go-librespot[24619]: time="2024-04-24T09:56:20+10:00" level=debug msg="completed keyexchange" Apr 24 09:56:21 digimusic volumio[834]: info: Initializing connection to go-librespot Websocket Apr 24 09:56:21 digimusic volumio[834]: info: Connection to go-librespot Websocket established Apr 24 09:56:21 digimusic go-librespot[24619]: time="2024-04-24T09:56:21+10:00" level=debug msg="new websocket client" Apr 24 09:56:21 digimusic go-librespot[24619]: time="2024-04-24T09:56:21+10:00" level=debug msg="completed challenge" Apr 24 09:56:21 digimusic go-librespot[24619]: time="2024-04-24T09:56:21+10:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 24 09:56:21 digimusic systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 24 09:56:21 digimusic systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 24 09:56:21 digimusic volumio[834]: info: Connection to go-librespot Websocket closed Apr 24 09:56:24 digimusic volumio[834]: info: Getting Spotify volume Apr 24 09:56:24 digimusic volumio[834]: (node:834) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 24 09:56:24 digimusic volumio[834]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 24 09:56:24 digimusic volumio[834]: (node:834) 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: 20263) Apr 24 09:56:24 digimusic volumio[834]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Apr 24 09:56:24 digimusic volumio[834]: info: CoreCommandRouter::volumioGetState Apr 24 09:56:24 digimusic volumio[834]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 09:56:24 digimusic volumio[834]: info: Initializing connection to go-librespot Websocket Apr 24 09:56:24 digimusic volumio[834]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 24 09:56:24 digimusic systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 24 09:56:24 digimusic systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38216. Apr 24 09:56:24 digimusic systemd[1]: Stopped go-librespot Daemon. Apr 24 09:56:24 digimusic systemd[1]: Started go-librespot Daemon. Apr 24 09:56:24 digimusic go-librespot[24627]: Librespot-go daemon starting... Apr 24 09:56:24 digimusic go-librespot[24627]: time="2024-04-24T09:56:24+10:00" level=info msg="generated new device id: 2f8e53d5bc0f52553839923408bb19b2bbb648eb" Apr 24 09:56:24 digimusic go-librespot[24627]: time="2024-04-24T09:56:24+10:00" level=debug msg="stored credentials found for drhonk" Apr 24 09:56:25 digimusic go-librespot[24627]: time="2024-04-24T09:56:25+10:00" level=debug msg="obtained new client token: AAB9GlY00pwLSf30HOSm5rW1EjcKvsRT4Dta5GLTN4qWWgsce1pL76NZtAw/AB4IvrHDuUaj+3lah44+wOPRpAfWykS4c9n7wRRgHIDWIoKmjA8LuAE86NkI4gyngkra2PnnCiJCUOJQZ/w6ncjbwj/zW39Nq+ds3R0HjuDLP7zYvVMSgh6zX5rXcLnyhxkBOMmaHDKOjzzRvkUjH2KSy2ZQmU7l2rcslj0QF/ICs6fW7GoFhlB6JpJvTWGi" Apr 24 09:56:25 digimusic go-librespot[24627]: time="2024-04-24T09:56:25+10:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Apr 24 09:56:25 digimusic go-librespot[24627]: time="2024-04-24T09:56:25+10:00" level=debug msg="completed keyexchange" Apr 24 09:56:26 digimusic go-librespot[24627]: time="2024-04-24T09:56:26+10:00" level=debug msg="completed challenge" Apr 24 09:56:26 digimusic go-librespot[24627]: time="2024-04-24T09:56:26+10:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 24 09:56:26 digimusic systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 24 09:56:26 digimusic systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 24 09:56:27 digimusic volumio[834]: info: Initializing connection to go-librespot Websocket Apr 24 09:56:27 digimusic volumio[834]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 24 09:56:29 digimusic systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 24 09:56:29 digimusic systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38217. Apr 24 09:56:29 digimusic systemd[1]: Stopped go-librespot Daemon. Apr 24 09:56:29 digimusic systemd[1]: Started go-librespot Daemon. Apr 24 09:56:29 digimusic go-librespot[24636]: Librespot-go daemon starting... Apr 24 09:56:29 digimusic go-librespot[24636]: time="2024-04-24T09:56:29+10:00" level=info msg="generated new device id: f964d36f0102cc0e8cf899c995cd2c4996422ba6" Apr 24 09:56:29 digimusic go-librespot[24636]: time="2024-04-24T09:56:29+10:00" level=debug msg="stored credentials found for drhonk" Apr 24 09:56:29 digimusic go-librespot[24636]: time="2024-04-24T09:56:29+10:00" level=debug msg="obtained new client token: AACXl6H6VKDZF2we8AUVkmp986EWPGBmOE00qg/OZ8Opt0jKkdbBlABvYy4sxaBoHlPrMGm3lrh/sDHk+4nOWHbJ58Xq6XaMzG+6gOYmYiZb5UKF4h9k12M73VeGmaQIft75hDzB80d+y/8qglyV6XBXZuawwru2tHMIalqV2FxgkhrLG97Jbjuc/UbwfYWbP/uX2yZM2lkPlbQAD4qxFPrhThQL8Ts5uz0MF5aKtAbuQEtjBv6rDrWqORsw228=" Apr 24 09:56:30 digimusic go-librespot[24636]: time="2024-04-24T09:56:30+10:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Apr 24 09:56:30 digimusic go-librespot[24636]: time="2024-04-24T09:56:30+10:00" level=debug msg="completed keyexchange" Apr 24 09:56:30 digimusic volumio[834]: info: Initializing connection to go-librespot Websocket Apr 24 09:56:30 digimusic volumio[834]: info: Connection to go-librespot Websocket established Apr 24 09:56:30 digimusic go-librespot[24636]: time="2024-04-24T09:56:30+10:00" level=debug msg="new websocket client" Apr 24 09:56:30 digimusic go-librespot[24636]: time="2024-04-24T09:56:30+10:00" level=debug msg="completed challenge" Apr 24 09:56:31 digimusic go-librespot[24636]: time="2024-04-24T09:56:31+10:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 24 09:56:31 digimusic systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 24 09:56:31 digimusic systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 24 09:56:31 digimusic volumio[834]: info: Connection to go-librespot Websocket closed Apr 24 09:56:33 digimusic volumio[834]: info: Getting Spotify volume Apr 24 09:56:33 digimusic volumio[834]: (node:834) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 24 09:56:33 digimusic volumio[834]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 24 09:56:33 digimusic volumio[834]: (node:834) 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: 20264) Apr 24 09:56:33 digimusic volumio[834]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Apr 24 09:56:33 digimusic volumio[834]: info: CoreCommandRouter::volumioGetState Apr 24 09:56:33 digimusic volumio[834]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 09:56:34 digimusic volumio[834]: info: Initializing connection to go-librespot Websocket Apr 24 09:56:34 digimusic volumio[834]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 24 09:56:34 digimusic systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 24 09:56:34 digimusic systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38218. Apr 24 09:56:34 digimusic systemd[1]: Stopped go-librespot Daemon. Apr 24 09:56:34 digimusic systemd[1]: Started go-librespot Daemon. Apr 24 09:56:34 digimusic go-librespot[24703]: Librespot-go daemon starting... Apr 24 09:56:34 digimusic go-librespot[24703]: time="2024-04-24T09:56:34+10:00" level=info msg="generated new device id: bf95dce1ee2998fa565961409761b97b884536d0" Apr 24 09:56:34 digimusic go-librespot[24703]: time="2024-04-24T09:56:34+10:00" level=debug msg="stored credentials found for drhonk" Apr 24 09:56:34 digimusic go-librespot[24703]: time="2024-04-24T09:56:34+10:00" level=debug msg="obtained new client token: AAAJr0HmKzKIOqb4WNRkrKQpWfrqWMUieK8ddRKFrUyr6JbOJ9fP8VT9WEyz8kqOxurJC0KX/J3oeRllL6IF9Td4S2ctoHfmTgLQt6FajuYDi8ITDkmobKVqcM+Umz2NkQJtcOvwKsGR3GLSbU4PBGS9SFFWxjys+vg+1ImAjy/FjpODH0YPLcxEByeSJJGjxcj5NgMutAUG4yOw5myZXTMfHBs9EdpXGUqX4nnOH0LVtW+52+46W/TzhpOoS0E=" Apr 24 09:56:34 digimusic go-librespot[24703]: time="2024-04-24T09:56:34+10:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 24 09:56:35 digimusic go-librespot[24703]: time="2024-04-24T09:56:35+10:00" level=debug msg="completed keyexchange" Apr 24 09:56:35 digimusic go-librespot[24703]: time="2024-04-24T09:56:35+10:00" level=debug msg="completed challenge" Apr 24 09:56:35 digimusic go-librespot[24703]: time="2024-04-24T09:56:35+10:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 24 09:56:35 digimusic systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 24 09:56:35 digimusic systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 24 09:56:37 digimusic volumio[834]: info: Initializing connection to go-librespot Websocket Apr 24 09:56:37 digimusic volumio[834]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 24 09:56:39 digimusic systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 24 09:56:39 digimusic systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38219. Apr 24 09:56:39 digimusic systemd[1]: Stopped go-librespot Daemon. Apr 24 09:56:39 digimusic systemd[1]: Started go-librespot Daemon. Apr 24 09:56:39 digimusic go-librespot[24712]: Librespot-go daemon starting... Apr 24 09:56:39 digimusic go-librespot[24712]: time="2024-04-24T09:56:39+10:00" level=info msg="generated new device id: 304a42c4c471ae46bafd051a9fa3dc8131220e28" Apr 24 09:56:39 digimusic go-librespot[24712]: time="2024-04-24T09:56:39+10:00" level=debug msg="stored credentials found for drhonk" Apr 24 09:56:39 digimusic go-librespot[24712]: time="2024-04-24T09:56:39+10:00" level=debug msg="obtained new client token: AAC3bMqfBHo/5EzAg57l119aUKP6p8PDZlEokRqg7dn+MfW4Vv15IGCcInNRe3D69jDeoYa+jK2Ba3raL/CzEdg0726F7c1IBH+g8VhAcr4MqmfqnKfqE0HYQwa0+tpDsrhduQcfRqYyrVLJ9p9P7D3sMcge/V2Wtq6MTnJsNSJWgkitZ6W5kkSx7N4tR9ePZTj4XNZw2JSvkz99mRl/GIr2MCScZDTAr8Dz6fZ6rXVHtQXC9ohlCgOWLihlSp8=" Apr 24 09:56:39 digimusic go-librespot[24712]: time="2024-04-24T09:56:39+10:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 24 09:56:39 digimusic go-librespot[24712]: time="2024-04-24T09:56:39+10:00" level=debug msg="completed keyexchange" Apr 24 09:56:40 digimusic volumio[834]: info: Initializing connection to go-librespot Websocket Apr 24 09:56:40 digimusic go-librespot[24712]: time="2024-04-24T09:56:40+10:00" level=debug msg="new websocket client" Apr 24 09:56:40 digimusic volumio[834]: info: Connection to go-librespot Websocket established Apr 24 09:56:40 digimusic go-librespot[24712]: time="2024-04-24T09:56:40+10:00" level=debug msg="completed challenge" Apr 24 09:56:40 digimusic go-librespot[24712]: time="2024-04-24T09:56:40+10:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 24 09:56:40 digimusic systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 24 09:56:40 digimusic systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 24 09:56:40 digimusic volumio[834]: info: Connection to go-librespot Websocket closed Apr 24 09:56:43 digimusic volumio[834]: info: Getting Spotify volume Apr 24 09:56:43 digimusic volumio[834]: (node:834) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 24 09:56:43 digimusic volumio[834]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 24 09:56:43 digimusic volumio[834]: (node:834) 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: 20265) Apr 24 09:56:43 digimusic volumio[834]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Apr 24 09:56:43 digimusic volumio[834]: info: CoreCommandRouter::volumioGetState Apr 24 09:56:43 digimusic volumio[834]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 09:56:43 digimusic volumio[834]: info: Initializing connection to go-librespot Websocket Apr 24 09:56:43 digimusic volumio[834]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 24 09:56:43 digimusic systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 24 09:56:43 digimusic systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38220. Apr 24 09:56:43 digimusic systemd[1]: Stopped go-librespot Daemon. Apr 24 09:56:43 digimusic systemd[1]: Started go-librespot Daemon. Apr 24 09:56:43 digimusic go-librespot[24721]: Librespot-go daemon starting... Apr 24 09:56:43 digimusic go-librespot[24721]: time="2024-04-24T09:56:43+10:00" level=info msg="generated new device id: 526640d92ca3fa4a899ac5abf7afb91c1ec9f780" Apr 24 09:56:43 digimusic go-librespot[24721]: time="2024-04-24T09:56:43+10:00" level=debug msg="stored credentials found for drhonk" Apr 24 09:56:44 digimusic go-librespot[24721]: time="2024-04-24T09:56:44+10:00" level=debug msg="obtained new client token: AABaxOAcS8JzdXkeLDgaaXsA9/aJj0FWmhaQKUvdiZHzfXa/rHAMSusAPnS1+x5e8G2j3cgDWRZRkwszATXVRahQU3JhhLLj8cuiYQwriIJC+wsXyX0vPBci0JUETjgdkWltC95D7t+LL/TWaKeODP+MijWi7mOnfoSwAqsQQ13b6LQlqjH1PaZd5Aq8iyLh2ceX+0nMatrB1YaqxFh0ad/KRpt9uKQ7SYzK8Pe/+W2iOYZBFD2MNs2TFslA" Apr 24 09:56:44 digimusic go-librespot[24721]: time="2024-04-24T09:56:44+10:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Apr 24 09:56:44 digimusic go-librespot[24721]: time="2024-04-24T09:56:44+10:00" level=debug msg="completed keyexchange" Apr 24 09:56:45 digimusic go-librespot[24721]: time="2024-04-24T09:56:45+10:00" level=debug msg="completed challenge" Apr 24 09:56:45 digimusic go-librespot[24721]: time="2024-04-24T09:56:45+10:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 24 09:56:45 digimusic systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 24 09:56:45 digimusic systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 24 09:56:46 digimusic volumio[834]: info: Initializing connection to go-librespot Websocket Apr 24 09:56:46 digimusic volumio[834]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 24 09:56:48 digimusic volumio[834]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 24 09:56:48 digimusic volumio[834]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Apr 24 09:56:48 digimusic systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 24 09:56:48 digimusic systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38221. Apr 24 09:56:48 digimusic systemd[1]: Stopped go-librespot Daemon. Apr 24 09:56:48 digimusic systemd[1]: Started go-librespot Daemon. Apr 24 09:56:48 digimusic go-librespot[24729]: Librespot-go daemon starting... Apr 24 09:56:48 digimusic go-librespot[24729]: time="2024-04-24T09:56:48+10:00" level=info msg="generated new device id: 280f68c18e80527af63238546ff8eab0c9d94b69" Apr 24 09:56:48 digimusic go-librespot[24729]: time="2024-04-24T09:56:48+10:00" level=debug msg="stored credentials found for drhonk" Apr 24 09:56:48 digimusic go-librespot[24729]: time="2024-04-24T09:56:48+10:00" level=debug msg="obtained new client token: AABCLB8Bm2Fe8JrM+V8bp/RN2u+E63S+WRuz8jCK0DohBeThQUYWKAXC9YFED6cYAbzYsJXjo1x59bu+mUlxUgpfbccy7+Z0v7KBTiZUXJrGuASXcUqaVQnHFVJE4LUMY3O1SArc2mQaGWmF9pbaZYDVJMTLU0n8xCJI8ljtW+Uu90zYBu+sqjMShhm8fW9oSqbIGfmDpmLMW/UZftxvDNcVSP3no+OuqTC2oIODmJndzEwJPKbE82QeKD9hY3g=" Apr 24 09:56:49 digimusic go-librespot[24729]: time="2024-04-24T09:56:49+10:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 24 09:56:49 digimusic go-librespot[24729]: time="2024-04-24T09:56:49+10:00" level=debug msg="completed keyexchange" Apr 24 09:56:49 digimusic volumio[834]: info: Initializing connection to go-librespot Websocket Apr 24 09:56:49 digimusic go-librespot[24729]: time="2024-04-24T09:56:49+10:00" level=debug msg="new websocket client" Apr 24 09:56:49 digimusic volumio[834]: info: Connection to go-librespot Websocket established Apr 24 09:56:49 digimusic go-librespot[24729]: time="2024-04-24T09:56:49+10:00" level=debug msg="completed challenge" Apr 24 09:56:50 digimusic go-librespot[24729]: time="2024-04-24T09:56:50+10:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 24 09:56:50 digimusic volumio[834]: info: Connection to go-librespot Websocket closed Apr 24 09:56:50 digimusic systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 24 09:56:50 digimusic systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 24 09:56:52 digimusic volumio[834]: info: Getting Spotify volume Apr 24 09:56:52 digimusic volumio[834]: (node:834) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 24 09:56:52 digimusic volumio[834]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 24 09:56:52 digimusic volumio[834]: (node:834) 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: 20266) Apr 24 09:56:52 digimusic volumio[834]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Apr 24 09:56:52 digimusic volumio[834]: info: CoreCommandRouter::volumioGetState Apr 24 09:56:52 digimusic volumio[834]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 09:56:53 digimusic volumio[834]: info: Initializing connection to go-librespot Websocket Apr 24 09:56:53 digimusic volumio[834]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 24 09:56:53 digimusic systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 24 09:56:53 digimusic systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38222. Apr 24 09:56:53 digimusic systemd[1]: Stopped go-librespot Daemon. Apr 24 09:56:53 digimusic systemd[1]: Started go-librespot Daemon. Apr 24 09:56:53 digimusic go-librespot[24738]: Librespot-go daemon starting... Apr 24 09:56:53 digimusic go-librespot[24738]: time="2024-04-24T09:56:53+10:00" level=info msg="generated new device id: 256e8120fa6c66251f383f637cda1597e8a36150" Apr 24 09:56:53 digimusic go-librespot[24738]: time="2024-04-24T09:56:53+10:00" level=debug msg="stored credentials found for drhonk" Apr 24 09:56:53 digimusic go-librespot[24738]: time="2024-04-24T09:56:53+10:00" level=debug msg="obtained new client token: AABTV25/jZHyFdCbbktt3a4bWDmE+7xwhbCEFxE3JDnSQnLgJs9uF5aE3G+5hsOcUpRTJIxoq14yAAaUZn+SVwqQ4I5y7TJKRvyCEb9izBo3FNAR1bzkkMGcGZ/Yp4z+ZoyP43q+o6WbtjdNDO1/qewzuH/BtDQpH5SMVzFj5CVOH8qt5cQnFRwgc24TsmJjFV4/Q9UajReEjdSp9WEkWmTTnTXSWgRulCCVnJeEqZgsmf10ZpHEW985GZj+6nk=" Apr 24 09:56:53 digimusic go-librespot[24738]: time="2024-04-24T09:56:53+10:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 24 09:56:54 digimusic go-librespot[24738]: time="2024-04-24T09:56:54+10:00" level=debug msg="completed keyexchange" Apr 24 09:56:54 digimusic volumio[834]: info: Stopping peppyspectrum service Apr 24 09:56:54 digimusic volumio[834]: info: CoreStateMachine::stop Apr 24 09:56:54 digimusic volumio[834]: info: CoreStateMachine::serviceStop Apr 24 09:56:54 digimusic volumio[834]: info: CoreCommandRouter::serviceStop Apr 24 09:56:54 digimusic volumio[834]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 24 09:56:54 digimusic volumio[834]: TypeError: Cannot read property 'then' of undefined Apr 24 09:56:54 digimusic volumio[834]: at peppyspectrum.onStop (/data/plugins/user_interface/peppyspectrum/index.js:58:43) Apr 24 09:56:54 digimusic volumio[834]: at PluginManager.stopPlugin (/volumio/app/pluginmanager.js:460:30) Apr 24 09:56:54 digimusic volumio[834]: at PluginManager.disableAndStopPlugin (/volumio/app/pluginmanager.js:1883:8) Apr 24 09:56:54 digimusic volumio[834]: at CoreCommandRouter.disableAndStopPlugin (/volumio/app/index.js:1531:29) Apr 24 09:56:54 digimusic volumio[834]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1356:47) Apr 24 09:56:54 digimusic volumio[834]: at Socket.emit (events.js:315:20) Apr 24 09:56:54 digimusic volumio[834]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 Apr 24 09:56:54 digimusic volumio[834]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Apr 24 09:56:54 digimusic volumio[834]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 24 09:56:54 digimusic go-librespot[24738]: time="2024-04-24T09:56:54+10:00" level=debug msg="completed challenge" Apr 24 09:56:54 digimusic sudo[24755]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-04-24 09:55 Apr 24 09:56:54 digimusic sudo[24755]: 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"