-- Logs begin at Sun 2024-07-14 03:06:14 UTC, end at Sun 2024-07-14 05:23:33 UTC. --
Jul 14 05:22:01 minione volumio[627]: info: Getting Spotify volume
Jul 14 05:22:01 minione volumio[627]: (node:627) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 14 05:22:01 minione volumio[627]:     at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16)
Jul 14 05:22:01 minione volumio[627]: (node:627) 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: 2905)
Jul 14 05:22:01 minione volumio[627]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7
Jul 14 05:22:01 minione volumio[627]: info: CoreCommandRouter::volumioGetState
Jul 14 05:22:01 minione volumio[627]: info: CorePlayQueue::getTrack 0
Jul 14 05:22:01 minione volumio[627]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60
Jul 14 05:22:02 minione volumio[627]: info: Initializing connection to go-librespot Websocket
Jul 14 05:22:02 minione systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 14 05:22:02 minione systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7741.
Jul 14 05:22:02 minione systemd[1]: Stopped go-librespot Daemon.
Jul 14 05:22:02 minione volumio[627]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 14 05:22:02 minione systemd[1]: Started go-librespot Daemon.
Jul 14 05:22:02 minione go-librespot[2334]: Librespot-go daemon starting...
Jul 14 05:22:02 minione go-librespot[2334]: time="2024-07-14T05:22:02Z" level=info msg="generated new device id: 9160ee5b8e5ceed138467cf1b6b430180cb41026"
Jul 14 05:22:02 minione go-librespot[2334]: time="2024-07-14T05:22:02Z" level=debug msg="stored credentials not found"
Jul 14 05:22:03 minione go-librespot[2334]: time="2024-07-14T05:22:03Z" level=debug msg="obtained new client token: AADUoVobtH7kfafJnMx1Ngis7ZqXIeu+Re3NIDwIr/iAqAOZzYnkL9R+uuPHfjBrrWG68wQpZsSD8serY45MCqfiMmrX7KQlwGxGZq1PXiB2smVKzrhaXtiy5QUdUEohn9SkjHg7UBrgeTUajyi7dg3iMOskvvvtdoKGlVGrNnhTjqVeKfNO1cNR6dwODbTXgz/nuwBouyJ/6wDdA6iTu6O/VN/+1lLnOqrTcc+XZpVqWGaLQBKDOKsxsUe0"
Jul 14 05:22:03 minione go-librespot[2334]: time="2024-07-14T05:22:03Z" 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]"
Jul 14 05:22:04 minione go-librespot[2334]: time="2024-07-14T05:22:04Z" level=debug msg="completed keyexchange"
Jul 14 05:22:04 minione go-librespot[2334]: time="2024-07-14T05:22:04Z" level=debug msg="completed challenge"
Jul 14 05:22:05 minione go-librespot[2334]: time="2024-07-14T05:22:05Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials"
Jul 14 05:22:05 minione systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 14 05:22:05 minione systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 14 05:22:05 minione volumio[627]: info: Initializing connection to go-librespot Websocket
Jul 14 05:22:05 minione volumio[627]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 14 05:22:08 minione systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 14 05:22:08 minione systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7742.
Jul 14 05:22:08 minione systemd[1]: Stopped go-librespot Daemon.
Jul 14 05:22:08 minione systemd[1]: Started go-librespot Daemon.
Jul 14 05:22:08 minione go-librespot[2342]: Librespot-go daemon starting...
Jul 14 05:22:08 minione go-librespot[2342]: time="2024-07-14T05:22:08Z" level=info msg="generated new device id: e23654861e51d0ce911161831cae41d1d00d8307"
Jul 14 05:22:08 minione go-librespot[2342]: time="2024-07-14T05:22:08Z" level=debug msg="stored credentials not found"
Jul 14 05:22:08 minione volumio[627]: info: Initializing connection to go-librespot Websocket
Jul 14 05:22:08 minione volumio[627]: info: Connection to go-librespot Websocket established
Jul 14 05:22:08 minione go-librespot[2342]: time="2024-07-14T05:22:08Z" level=debug msg="new websocket client"
Jul 14 05:22:09 minione go-librespot[2342]: time="2024-07-14T05:22:09Z" level=debug msg="obtained new client token: AAA6eiG7ml+9OUWCxnwu0D64nPq6q0ZjJ/aaSULk6XNfsvjI7bBGKdQUhRN4S+D4NWALwckJjBaUWMcQcnLd9VX2CSLkSzb83oVwPaQl1SmeR3C8iwn02ijyM32+tHO/22qD3sIWOTON2u4rqfZYifDyjhKxEO9RToK8M37Z81z210lzc4WKO2qHLF76VuE/UOS7xylRQcvn1oeeoAlMKFK5cw8hyfU4QSvvIF8fPQy1bMATEH70H6RjxQ=="
Jul 14 05:22:09 minione go-librespot[2342]: time="2024-07-14T05:22:09Z" 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]"
Jul 14 05:22:10 minione go-librespot[2342]: time="2024-07-14T05:22:10Z" level=debug msg="completed keyexchange"
Jul 14 05:22:10 minione go-librespot[2342]: time="2024-07-14T05:22:10Z" level=debug msg="completed challenge"
Jul 14 05:22:10 minione go-librespot[2342]: time="2024-07-14T05:22:10Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials"
Jul 14 05:22:10 minione systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 14 05:22:10 minione systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 14 05:22:10 minione volumio[627]: info: Connection to go-librespot Websocket closed
Jul 14 05:22:11 minione volumio[627]: info: Getting Spotify volume
Jul 14 05:22:11 minione volumio[627]: (node:627) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 14 05:22:11 minione volumio[627]:     at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16)
Jul 14 05:22:11 minione volumio[627]: (node:627) 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: 2906)
Jul 14 05:22:11 minione volumio[627]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7
Jul 14 05:22:11 minione volumio[627]: info: CoreCommandRouter::volumioGetState
Jul 14 05:22:11 minione volumio[627]: info: CorePlayQueue::getTrack 0
Jul 14 05:22:11 minione volumio[627]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60
Jul 14 05:22:13 minione volumio[627]: info: Initializing connection to go-librespot Websocket
Jul 14 05:22:13 minione volumio[627]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 14 05:22:14 minione systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 14 05:22:14 minione systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7743.
Jul 14 05:22:14 minione systemd[1]: Stopped go-librespot Daemon.
Jul 14 05:22:14 minione systemd[1]: Started go-librespot Daemon.
Jul 14 05:22:14 minione go-librespot[2350]: Librespot-go daemon starting...
Jul 14 05:22:14 minione go-librespot[2350]: time="2024-07-14T05:22:14Z" level=info msg="generated new device id: db9a40b5ad6e43069b27a7ade7e1c549b12d7fb4"
Jul 14 05:22:14 minione go-librespot[2350]: time="2024-07-14T05:22:14Z" level=debug msg="stored credentials not found"
Jul 14 05:22:14 minione go-librespot[2350]: time="2024-07-14T05:22:14Z" level=debug msg="obtained new client token: AAA7qzPSR4x5mFLQBevSy4amZ+av2xf6+1sc3ze9YnlygEraw+CLz4n9wD+wYW2B/INJ79394uq9cca5f4BOUWfFKBPF/8lMF72NXR0gedlRGqRD33j9nnhwhByy9GvgOIFh6vTF6LPe/ydGJIZF2mWJ7s0aHW5ncacPgI09LzaBzNZ/ySEHw1ctj5lzwbPQoXpcJOyflOcC/RrPLlhFEbuCUgRBqzMlRmJ7mKZRYlFvEBRZqnRlV2kYFQul"
Jul 14 05:22:15 minione go-librespot[2350]: time="2024-07-14T05:22:15Z" 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]"
Jul 14 05:22:15 minione go-librespot[2350]: time="2024-07-14T05:22:15Z" level=debug msg="completed keyexchange"
Jul 14 05:22:16 minione go-librespot[2350]: time="2024-07-14T05:22:16Z" level=debug msg="completed challenge"
Jul 14 05:22:16 minione go-librespot[2350]: time="2024-07-14T05:22:16Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials"
Jul 14 05:22:16 minione systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 14 05:22:16 minione systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 14 05:22:16 minione volumio[627]: info: Initializing connection to go-librespot Websocket
Jul 14 05:22:16 minione volumio[627]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 14 05:22:19 minione systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 14 05:22:19 minione systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7744.
Jul 14 05:22:19 minione systemd[1]: Stopped go-librespot Daemon.
Jul 14 05:22:19 minione systemd[1]: Started go-librespot Daemon.
Jul 14 05:22:19 minione go-librespot[2359]: Librespot-go daemon starting...
Jul 14 05:22:19 minione go-librespot[2359]: time="2024-07-14T05:22:19Z" level=info msg="generated new device id: 21baac1c7336ebed77e2d928acce7214a1830df6"
Jul 14 05:22:19 minione go-librespot[2359]: time="2024-07-14T05:22:19Z" level=debug msg="stored credentials not found"
Jul 14 05:22:19 minione volumio[627]: info: Initializing connection to go-librespot Websocket
Jul 14 05:22:19 minione go-librespot[2359]: time="2024-07-14T05:22:19Z" level=debug msg="new websocket client"
Jul 14 05:22:19 minione volumio[627]: info: Connection to go-librespot Websocket established
Jul 14 05:22:20 minione go-librespot[2359]: time="2024-07-14T05:22:20Z" level=debug msg="obtained new client token: AABwC+lga/hz+U3+byM/kGLvQ4/stq3DaXCmFiwmYM208NvalCbaLJK6DtzaG5YlAKP4xmPLMAm7YH7g93yDZ+fBWQTnuCmFcMTP/uhp2tYfclJDRhMTdshiLUvZh3Q4Bo19fPoZ/r6SIbfM528033LiOoe2P70GV2uQFVTZkgaCHmvFjv9usKpm8RHg4qPuGfIvJjHZ2UWmyKllXEnzI0WNK5RA2Yqtp3KXF4fcZkatg0j7tgfhBNZu4w=="
Jul 14 05:22:20 minione go-librespot[2359]: time="2024-07-14T05:22:20Z" 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]"
Jul 14 05:22:20 minione go-librespot[2359]: time="2024-07-14T05:22:20Z" level=debug msg="completed keyexchange"
Jul 14 05:22:21 minione go-librespot[2359]: time="2024-07-14T05:22:21Z" level=debug msg="completed challenge"
Jul 14 05:22:21 minione go-librespot[2359]: time="2024-07-14T05:22:21Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials"
Jul 14 05:22:21 minione systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 14 05:22:21 minione systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 14 05:22:21 minione volumio[627]: info: Connection to go-librespot Websocket closed
Jul 14 05:22:22 minione volumio[627]: info: Getting Spotify volume
Jul 14 05:22:22 minione volumio[627]: (node:627) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 14 05:22:22 minione volumio[627]:     at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16)
Jul 14 05:22:22 minione volumio[627]: (node:627) 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: 2907)
Jul 14 05:22:22 minione volumio[627]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7
Jul 14 05:22:23 minione volumio[627]: info: CoreCommandRouter::volumioGetState
Jul 14 05:22:23 minione volumio[627]: info: CorePlayQueue::getTrack 0
Jul 14 05:22:23 minione volumio[627]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60
Jul 14 05:22:24 minione volumio[627]: info: Initializing connection to go-librespot Websocket
Jul 14 05:22:24 minione volumio[627]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 14 05:22:24 minione systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 14 05:22:24 minione systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7745.
Jul 14 05:22:24 minione systemd[1]: Stopped go-librespot Daemon.
Jul 14 05:22:24 minione systemd[1]: Started go-librespot Daemon.
Jul 14 05:22:24 minione go-librespot[2367]: Librespot-go daemon starting...
Jul 14 05:22:24 minione go-librespot[2367]: time="2024-07-14T05:22:24Z" level=info msg="generated new device id: 159a5e26ea47ce4dbc5213213987a6bbc13fe9d3"
Jul 14 05:22:24 minione go-librespot[2367]: time="2024-07-14T05:22:24Z" level=debug msg="stored credentials not found"
Jul 14 05:22:25 minione go-librespot[2367]: time="2024-07-14T05:22:25Z" level=debug msg="obtained new client token: AAA7IE182+Gc5lGHLOGYc1S+AcnAcFJhmspGYwJSY+pFlOONFn7NXOhd+xWENQKMPRAc902o+6Fi1tlbP5p9b8uD2qy+t3KGlhZmLmEoK2DljQ3JVmwcPwZwzW8brVbgZSO9F/StRzdSbjsQ6EV1m9yAgCQcau0KDXfydvsRSE8pLyV8IffpCYxAA8HX94wusJvNijg6n0IbKK17hh39pvLIW2knwGtRax1LFuWv4dw1FyPkw7T9yttSew=="
Jul 14 05:22:25 minione go-librespot[2367]: time="2024-07-14T05:22:25Z" 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]"
Jul 14 05:22:25 minione go-librespot[2367]: time="2024-07-14T05:22:25Z" level=debug msg="completed keyexchange"
Jul 14 05:22:25 minione go-librespot[2367]: time="2024-07-14T05:22:25Z" level=debug msg="completed challenge"
Jul 14 05:22:26 minione go-librespot[2367]: time="2024-07-14T05:22:26Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials"
Jul 14 05:22:26 minione systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 14 05:22:26 minione systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 14 05:22:27 minione volumio[627]: info: Initializing connection to go-librespot Websocket
Jul 14 05:22:27 minione volumio[627]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 14 05:22:29 minione systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 14 05:22:29 minione systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7746.
Jul 14 05:22:29 minione systemd[1]: Stopped go-librespot Daemon.
Jul 14 05:22:29 minione systemd[1]: Started go-librespot Daemon.
Jul 14 05:22:29 minione go-librespot[2375]: Librespot-go daemon starting...
Jul 14 05:22:29 minione go-librespot[2375]: time="2024-07-14T05:22:29Z" level=info msg="generated new device id: 0fc385064c4c8606f18a5515ffe6e3fe751c2a9c"
Jul 14 05:22:29 minione go-librespot[2375]: time="2024-07-14T05:22:29Z" level=debug msg="stored credentials not found"
Jul 14 05:22:30 minione go-librespot[2375]: time="2024-07-14T05:22:30Z" level=debug msg="obtained new client token: AABTA3Chs5VV4uQoXZvfFrptKNAafQFYfbTEBoe0ueuAPQYVi6F0fKQuOlpPSiiDwpyTJGs7vi/ED3ZZ2IpkFrW43/Q7UqS9JVhzsBXjziW3qkG1J0Zuy8588rMDTViHMUmhQh3QNFFfT5KExxjF0gUkmpOU2IwBnetGGgI4vdijERjZpXxV1asTplyDLTfGgBZkoamHF7138k1u6zE8OpM1YCFcgcBhKFZ0GqbiZh1kR1GY+ZPoSHYaTFSR"
Jul 14 05:22:30 minione volumio[627]: info: Initializing connection to go-librespot Websocket
Jul 14 05:22:30 minione go-librespot[2375]: time="2024-07-14T05:22:30Z" 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]"
Jul 14 05:22:30 minione volumio[627]: info: Connection to go-librespot Websocket established
Jul 14 05:22:30 minione go-librespot[2375]: time="2024-07-14T05:22:30Z" level=debug msg="new websocket client"
Jul 14 05:22:30 minione go-librespot[2375]: time="2024-07-14T05:22:30Z" level=debug msg="completed keyexchange"
Jul 14 05:22:31 minione go-librespot[2375]: time="2024-07-14T05:22:31Z" level=debug msg="completed challenge"
Jul 14 05:22:31 minione go-librespot[2375]: time="2024-07-14T05:22:31Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials"
Jul 14 05:22:31 minione volumio[627]: info: Connection to go-librespot Websocket closed
Jul 14 05:22:31 minione systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 14 05:22:31 minione systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 14 05:22:33 minione volumio[627]: info: Getting Spotify volume
Jul 14 05:22:33 minione volumio[627]: (node:627) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 14 05:22:33 minione volumio[627]:     at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16)
Jul 14 05:22:33 minione volumio[627]: (node:627) 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: 2908)
Jul 14 05:22:33 minione volumio[627]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7
Jul 14 05:22:33 minione volumio[627]: info: CoreCommandRouter::volumioGetState
Jul 14 05:22:33 minione volumio[627]: info: CorePlayQueue::getTrack 0
Jul 14 05:22:33 minione volumio[627]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60
Jul 14 05:22:34 minione volumio[627]: info: Initializing connection to go-librespot Websocket
Jul 14 05:22:34 minione volumio[627]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 14 05:22:34 minione systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 14 05:22:34 minione systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7747.
Jul 14 05:22:34 minione systemd[1]: Stopped go-librespot Daemon.
Jul 14 05:22:34 minione systemd[1]: Started go-librespot Daemon.
Jul 14 05:22:34 minione go-librespot[2383]: Librespot-go daemon starting...
Jul 14 05:22:34 minione go-librespot[2383]: time="2024-07-14T05:22:34Z" level=info msg="generated new device id: 34d165fab139284ad4814dba8da5dd32f0f8d7a0"
Jul 14 05:22:34 minione go-librespot[2383]: time="2024-07-14T05:22:34Z" level=debug msg="stored credentials not found"
Jul 14 05:22:35 minione go-librespot[2383]: time="2024-07-14T05:22:35Z" level=debug msg="obtained new client token: AACJmS3MwXnUpoJps4DljuNFK+990e/Bacrq5vKeqEf4oO2OTPwvcBlU31seNHNG1ScP11I1tflaH4lePcq3YfgemBFezvnT3E7/vnltvl/v5TrXXhgqpnRjny8I1PIh6k80ccI76F9TEHmBkBm2vt5GPEEkU9rj7EEDIshYTm94QQWnndXibj8TkFZnLf1AAWm65V4DIzS+PVa40Nslwm+r3ZviNX78I41XSbWVHjQ/cfkNhWjXozpX4g=="
Jul 14 05:22:35 minione go-librespot[2383]: time="2024-07-14T05:22:35Z" 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]"
Jul 14 05:22:35 minione go-librespot[2383]: time="2024-07-14T05:22:35Z" level=debug msg="completed keyexchange"
Jul 14 05:22:36 minione go-librespot[2383]: time="2024-07-14T05:22:36Z" level=debug msg="completed challenge"
Jul 14 05:22:36 minione go-librespot[2383]: time="2024-07-14T05:22:36Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials"
Jul 14 05:22:36 minione systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 14 05:22:36 minione systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 14 05:22:37 minione volumio[627]: info: Initializing connection to go-librespot Websocket
Jul 14 05:22:37 minione volumio[627]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 14 05:22:39 minione systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 14 05:22:39 minione systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7748.
Jul 14 05:22:39 minione systemd[1]: Stopped go-librespot Daemon.
Jul 14 05:22:39 minione systemd[1]: Started go-librespot Daemon.
Jul 14 05:22:39 minione go-librespot[2392]: Librespot-go daemon starting...
Jul 14 05:22:39 minione go-librespot[2392]: time="2024-07-14T05:22:39Z" level=info msg="generated new device id: 4e6bbb40581030e5c1b1443bfa115665a84f9b4c"
Jul 14 05:22:39 minione go-librespot[2392]: time="2024-07-14T05:22:39Z" level=debug msg="stored credentials not found"
Jul 14 05:22:40 minione volumio[627]: info: Initializing connection to go-librespot Websocket
Jul 14 05:22:40 minione go-librespot[2392]: time="2024-07-14T05:22:40Z" level=debug msg="new websocket client"
Jul 14 05:22:40 minione volumio[627]: info: Connection to go-librespot Websocket established
Jul 14 05:22:40 minione go-librespot[2392]: time="2024-07-14T05:22:40Z" level=debug msg="obtained new client token: AADXJ9cGpd+KY2b7z18Bu/nPLQemr6e6iYWwQ1/UPmI6qArP8h9c34HW6F+i3pbn/1ChxVzc7jyvnq/7Oqgc+qOdXefscBdKes54EMb+mtJcduhivCiUrvDJE4Ut6WfCHXwnZiJXbBUuNjvZOklanIno5jnJIkGxMrRbrQ6h/e2L8PFV4jJHoRRllJxN1ZizoCmzuf+7c1gB5niRdUAWabGrqrXf/EbIcU5MMUcpEauKpstsJ+Us8yRAZbxI"
Jul 14 05:22:40 minione go-librespot[2392]: time="2024-07-14T05:22:40Z" 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]"
Jul 14 05:22:41 minione go-librespot[2392]: time="2024-07-14T05:22:41Z" level=debug msg="completed keyexchange"
Jul 14 05:22:41 minione go-librespot[2392]: time="2024-07-14T05:22:41Z" level=debug msg="completed challenge"
Jul 14 05:22:41 minione go-librespot[2392]: time="2024-07-14T05:22:41Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials"
Jul 14 05:22:41 minione volumio[627]: info: Connection to go-librespot Websocket closed
Jul 14 05:22:41 minione systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 14 05:22:41 minione systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 14 05:22:43 minione volumio[627]: info: Getting Spotify volume
Jul 14 05:22:43 minione volumio[627]: (node:627) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 14 05:22:43 minione volumio[627]:     at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16)
Jul 14 05:22:43 minione volumio[627]: (node:627) 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: 2909)
Jul 14 05:22:43 minione volumio[627]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7
Jul 14 05:22:43 minione volumio[627]: info: CoreCommandRouter::volumioGetState
Jul 14 05:22:43 minione volumio[627]: info: CorePlayQueue::getTrack 0
Jul 14 05:22:43 minione volumio[627]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60
Jul 14 05:22:44 minione volumio[627]: info: Initializing connection to go-librespot Websocket
Jul 14 05:22:44 minione volumio[627]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 14 05:22:44 minione systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 14 05:22:44 minione systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7749.
Jul 14 05:22:44 minione systemd[1]: Stopped go-librespot Daemon.
Jul 14 05:22:44 minione systemd[1]: Started go-librespot Daemon.
Jul 14 05:22:44 minione go-librespot[2400]: Librespot-go daemon starting...
Jul 14 05:22:44 minione go-librespot[2400]: time="2024-07-14T05:22:44Z" level=info msg="generated new device id: ef41c13ff87e6e37311cd03771aee6f5dbcf2fbb"
Jul 14 05:22:44 minione go-librespot[2400]: time="2024-07-14T05:22:44Z" level=debug msg="stored credentials not found"
Jul 14 05:22:45 minione go-librespot[2400]: time="2024-07-14T05:22:45Z" level=debug msg="obtained new client token: AAD2mvwOyX2q3iUlORkR27oB3lOJ/Ue8SWsVMcDww7tRz3MnKtXmJ1SBwlmmu3BY5EyT8EEF3PmW3ZrgRohF5KmEkftJQLu0zSPAApu0hqbM+s+uLxd0aVqBmqnEBEroGYJ8/ZftBKV3oRWixgP7LKseoD4hQ3kVnq+GtAhlGkCRWjntyM9wilaugRmi8Xu0g50ONKAGtYWFMZgti2v8dDutmnOKLHpKy1lcOv6QSUyR2w6WICw7dRYORvJK"
Jul 14 05:22:45 minione go-librespot[2400]: time="2024-07-14T05:22:45Z" 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]"
Jul 14 05:22:46 minione go-librespot[2400]: time="2024-07-14T05:22:46Z" level=debug msg="completed keyexchange"
Jul 14 05:22:46 minione go-librespot[2400]: time="2024-07-14T05:22:46Z" level=debug msg="completed challenge"
Jul 14 05:22:46 minione go-librespot[2400]: time="2024-07-14T05:22:46Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials"
Jul 14 05:22:46 minione systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 14 05:22:46 minione systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 14 05:22:47 minione volumio[627]: info: Initializing connection to go-librespot Websocket
Jul 14 05:22:47 minione volumio[627]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 14 05:22:50 minione systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 14 05:22:50 minione systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7750.
Jul 14 05:22:50 minione systemd[1]: Stopped go-librespot Daemon.
Jul 14 05:22:50 minione systemd[1]: Started go-librespot Daemon.
Jul 14 05:22:50 minione go-librespot[2408]: Librespot-go daemon starting...
Jul 14 05:22:50 minione go-librespot[2408]: time="2024-07-14T05:22:50Z" level=info msg="generated new device id: fec0a0d82536e0ba9bf29017e53715eea0c51a7b"
Jul 14 05:22:50 minione go-librespot[2408]: time="2024-07-14T05:22:50Z" level=debug msg="stored credentials not found"
Jul 14 05:22:50 minione volumio[627]: info: Initializing connection to go-librespot Websocket
Jul 14 05:22:50 minione go-librespot[2408]: time="2024-07-14T05:22:50Z" level=debug msg="obtained new client token: AAAjgUmblUSHeWx1I9SsGdMXZ3ycY7rc5laIjQ0TjMH53CwZ9LKG2bGQlMYbIWGKOPdBm+n0b5xYUXY8bIxUl+RCTU81YjN8s5ciTkr+X+c3g4fLzjhGORYPTLiK4LgwcjdCQps7v/XVXlJrBRi9nT92qudhIyR1NXvKOiWfsU/NmAlzivaoluHceuUYACkh4JdAjfd6SryE3r2TK3TPpcyJ6OIq3uPdQklq6tv/nfP7PGaf8ftSjtTrWm7N"
Jul 14 05:22:50 minione go-librespot[2408]: time="2024-07-14T05:22:50Z" level=debug msg="new websocket client"
Jul 14 05:22:50 minione volumio[627]: info: Connection to go-librespot Websocket established
Jul 14 05:22:51 minione go-librespot[2408]: time="2024-07-14T05:22:51Z" 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]"
Jul 14 05:22:51 minione go-librespot[2408]: time="2024-07-14T05:22:51Z" level=debug msg="completed keyexchange"
Jul 14 05:22:52 minione go-librespot[2408]: time="2024-07-14T05:22:52Z" level=debug msg="completed challenge"
Jul 14 05:22:52 minione go-librespot[2408]: time="2024-07-14T05:22:52Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials"
Jul 14 05:22:52 minione systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 14 05:22:52 minione systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 14 05:22:52 minione volumio[627]: info: Connection to go-librespot Websocket closed
Jul 14 05:22:53 minione volumio[627]: info: Getting Spotify volume
Jul 14 05:22:53 minione volumio[627]: (node:627) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 14 05:22:53 minione volumio[627]:     at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16)
Jul 14 05:22:53 minione volumio[627]: (node:627) 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: 2910)
Jul 14 05:22:53 minione volumio[627]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7
Jul 14 05:22:53 minione volumio[627]: info: CoreCommandRouter::volumioGetState
Jul 14 05:22:53 minione volumio[627]: info: CorePlayQueue::getTrack 0
Jul 14 05:22:53 minione volumio[627]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60
Jul 14 05:22:55 minione volumio[627]: info: Initializing connection to go-librespot Websocket
Jul 14 05:22:55 minione volumio[627]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 14 05:22:55 minione systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 14 05:22:55 minione systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7751.
Jul 14 05:22:55 minione systemd[1]: Stopped go-librespot Daemon.
Jul 14 05:22:55 minione systemd[1]: Started go-librespot Daemon.
Jul 14 05:22:55 minione go-librespot[2416]: Librespot-go daemon starting...
Jul 14 05:22:55 minione go-librespot[2416]: time="2024-07-14T05:22:55Z" level=info msg="generated new device id: 81befb8acc80b17bee27bbff1a0459e328cfe158"
Jul 14 05:22:55 minione go-librespot[2416]: time="2024-07-14T05:22:55Z" level=debug msg="stored credentials not found"
Jul 14 05:22:56 minione go-librespot[2416]: time="2024-07-14T05:22:56Z" level=debug msg="obtained new client token: AAB2h8Q7nX6H1XOfKGBr/9ueDoTHPzM1onSswK7yqHytLHM2/ZICQJ3JyAJ92+qkSG6wkkiTM+IMdePesY+Cy1gs92SnpD1gEYWwqcrJlHw1Xsxau4owkHTCLhzc8Bumi6vGTynR4M6rlcj7Pw52OJ3zR0BviuFx+RRV0gCZx8LtPCB/qGZfgvY17sERpBnPU0CKKTlbA19YRKVd3Qtxn/dysmaChkg5sWSI+qp6PVikxHxuT4V4Syk+8g=="
Jul 14 05:22:56 minione go-librespot[2416]: time="2024-07-14T05:22:56Z" 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]"
Jul 14 05:22:57 minione go-librespot[2416]: time="2024-07-14T05:22:57Z" level=debug msg="completed keyexchange"
Jul 14 05:22:57 minione go-librespot[2416]: time="2024-07-14T05:22:57Z" level=debug msg="completed challenge"
Jul 14 05:22:57 minione go-librespot[2416]: time="2024-07-14T05:22:57Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials"
Jul 14 05:22:57 minione systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 14 05:22:57 minione systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 14 05:22:58 minione volumio[627]: info: Initializing connection to go-librespot Websocket
Jul 14 05:22:58 minione volumio[627]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 14 05:23:00 minione systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 14 05:23:00 minione systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7752.
Jul 14 05:23:00 minione systemd[1]: Stopped go-librespot Daemon.
Jul 14 05:23:00 minione systemd[1]: Started go-librespot Daemon.
Jul 14 05:23:00 minione go-librespot[2425]: Librespot-go daemon starting...
Jul 14 05:23:00 minione go-librespot[2425]: time="2024-07-14T05:23:00Z" level=info msg="generated new device id: 59b08fbd994b5eab438df3dad029809e442ff56b"
Jul 14 05:23:00 minione go-librespot[2425]: time="2024-07-14T05:23:00Z" level=debug msg="stored credentials not found"
Jul 14 05:23:01 minione volumio[627]: info: Initializing connection to go-librespot Websocket
Jul 14 05:23:01 minione volumio[627]: info: Connection to go-librespot Websocket established
Jul 14 05:23:01 minione go-librespot[2425]: time="2024-07-14T05:23:01Z" level=debug msg="new websocket client"
Jul 14 05:23:01 minione go-librespot[2425]: time="2024-07-14T05:23:01Z" level=debug msg="obtained new client token: AAAHpI2HlmVL2lBA233B0sCO5NF5jc+n8pWWMghFqs1BPDuPALXTYJsy7NUzCWrpdYCml2fQRM///dDJX4Y8FfFZqACZxlYiNxgN9+SDQOhE3o9c48zQ3DxIvEO8zyNqurNM9em7oDC/2Ar3O6HI+R5OlNn8tWmhxhDliTgz0xjCzuEF+jtGnNMN4TqFkR5hTohyhUAb838awpaPVyiwTBLWkodWB4MfQRIMIOJrPmvnquBhiBvLrf1KQxIU"
Jul 14 05:23:01 minione go-librespot[2425]: time="2024-07-14T05:23:01Z" 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]"
Jul 14 05:23:02 minione go-librespot[2425]: time="2024-07-14T05:23:02Z" level=debug msg="completed keyexchange"
Jul 14 05:23:02 minione go-librespot[2425]: time="2024-07-14T05:23:02Z" level=debug msg="completed challenge"
Jul 14 05:23:02 minione go-librespot[2425]: time="2024-07-14T05:23:02Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials"
Jul 14 05:23:02 minione systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 14 05:23:02 minione systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 14 05:23:02 minione volumio[627]: info: Connection to go-librespot Websocket closed
Jul 14 05:23:04 minione volumio[627]: info: Getting Spotify volume
Jul 14 05:23:04 minione volumio[627]: (node:627) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 14 05:23:04 minione volumio[627]:     at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16)
Jul 14 05:23:04 minione volumio[627]: (node:627) 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: 2911)
Jul 14 05:23:04 minione volumio[627]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7
Jul 14 05:23:04 minione volumio[627]: info: CoreCommandRouter::volumioGetState
Jul 14 05:23:04 minione volumio[627]: info: CorePlayQueue::getTrack 0
Jul 14 05:23:04 minione volumio[627]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60
Jul 14 05:23:05 minione volumio[627]: info: Initializing connection to go-librespot Websocket
Jul 14 05:23:05 minione volumio[627]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 14 05:23:06 minione systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 14 05:23:06 minione systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7753.
Jul 14 05:23:06 minione systemd[1]: Stopped go-librespot Daemon.
Jul 14 05:23:06 minione systemd[1]: Started go-librespot Daemon.
Jul 14 05:23:06 minione go-librespot[2433]: Librespot-go daemon starting...
Jul 14 05:23:06 minione go-librespot[2433]: time="2024-07-14T05:23:06Z" level=info msg="generated new device id: b6d3d4359c81783a2c884a80cdbc3eee7810baa1"
Jul 14 05:23:06 minione go-librespot[2433]: time="2024-07-14T05:23:06Z" level=debug msg="stored credentials not found"
Jul 14 05:23:06 minione go-librespot[2433]: time="2024-07-14T05:23:06Z" level=debug msg="obtained new client token: AAD3wIlBAHIKfWqyFTMlwvXj/f7a7S1XIYMf+rREhr17+hiYvvClCbJhHWoG+i2zMsCpeKAqjWlkqPzSG+A3sKKZEglb0o0PY6LZNqtB2N8Y5JgW2UuZypF6+zcKZwozbj8VcE7yngAmrNXOsSMCy7RhGgUCVkRClAhUwNsmW1Yl9EtZfEoC745TxJ9zJkNYF+Awnrr/ZIStDItLUyR6SEO/Zwz3MqTVym6GgHnrEWbC3f/ILCujxoJsSaGZ"
Jul 14 05:23:07 minione go-librespot[2433]: time="2024-07-14T05:23:07Z" 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]"
Jul 14 05:23:07 minione go-librespot[2433]: time="2024-07-14T05:23:07Z" level=debug msg="completed keyexchange"
Jul 14 05:23:07 minione go-librespot[2433]: time="2024-07-14T05:23:07Z" level=debug msg="completed challenge"
Jul 14 05:23:08 minione go-librespot[2433]: time="2024-07-14T05:23:08Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials"
Jul 14 05:23:08 minione systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 14 05:23:08 minione systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 14 05:23:08 minione volumio[627]: info: Initializing connection to go-librespot Websocket
Jul 14 05:23:08 minione volumio[627]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 14 05:23:11 minione systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 14 05:23:11 minione systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7754.
Jul 14 05:23:11 minione systemd[1]: Stopped go-librespot Daemon.
Jul 14 05:23:11 minione systemd[1]: Started go-librespot Daemon.
Jul 14 05:23:11 minione go-librespot[2441]: Librespot-go daemon starting...
Jul 14 05:23:11 minione go-librespot[2441]: time="2024-07-14T05:23:11Z" level=info msg="generated new device id: f593e631c1e8f36e943a8c201100af89ae85ef11"
Jul 14 05:23:11 minione go-librespot[2441]: time="2024-07-14T05:23:11Z" level=debug msg="stored credentials not found"
Jul 14 05:23:11 minione volumio[627]: info: Initializing connection to go-librespot Websocket
Jul 14 05:23:11 minione go-librespot[2441]: time="2024-07-14T05:23:11Z" level=debug msg="new websocket client"
Jul 14 05:23:11 minione volumio[627]: info: Connection to go-librespot Websocket established
Jul 14 05:23:11 minione go-librespot[2441]: time="2024-07-14T05:23:11Z" level=debug msg="obtained new client token: AACsFRKdP4/OltAcLnlQEY0UWENxl2WOG8TyGd5a68+dxuQtbZE+5TNHSA3BJgltpB8jncoM8hqj+jAppZKoIuEToUeAaSz7+DogJWs7ewbfCVGELgFjsrj3lKW2tdcphlTQe5VREgDO4OqjSSSdY1GsMyQeiqWMI1Yhfm8f2+AGlIQfaoukNCQ4t/7e2Woppbi86q2+nj4Ml10y40y0afN9076t+NCt4JmiXcZsn9Hwg8OSzdge/VGpBng9"
Jul 14 05:23:12 minione go-librespot[2441]: time="2024-07-14T05:23:12Z" 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]"
Jul 14 05:23:12 minione go-librespot[2441]: time="2024-07-14T05:23:12Z" level=debug msg="completed keyexchange"
Jul 14 05:23:13 minione go-librespot[2441]: time="2024-07-14T05:23:13Z" level=debug msg="completed challenge"
Jul 14 05:23:13 minione go-librespot[2441]: time="2024-07-14T05:23:13Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials"
Jul 14 05:23:13 minione systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 14 05:23:13 minione systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 14 05:23:13 minione volumio[627]: info: Connection to go-librespot Websocket closed
Jul 14 05:23:14 minione volumio[627]: info: Getting Spotify volume
Jul 14 05:23:14 minione volumio[627]: (node:627) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 14 05:23:14 minione volumio[627]:     at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16)
Jul 14 05:23:14 minione volumio[627]: (node:627) 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: 2912)
Jul 14 05:23:14 minione volumio[627]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7
Jul 14 05:23:14 minione volumio[627]: info: CoreCommandRouter::volumioGetState
Jul 14 05:23:14 minione volumio[627]: info: CorePlayQueue::getTrack 0
Jul 14 05:23:14 minione volumio[627]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60
Jul 14 05:23:16 minione volumio[627]: info: Initializing connection to go-librespot Websocket
Jul 14 05:23:16 minione volumio[627]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 14 05:23:16 minione systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 14 05:23:16 minione systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7755.
Jul 14 05:23:16 minione systemd[1]: Stopped go-librespot Daemon.
Jul 14 05:23:16 minione systemd[1]: Started go-librespot Daemon.
Jul 14 05:23:16 minione go-librespot[2450]: Librespot-go daemon starting...
Jul 14 05:23:16 minione go-librespot[2450]: time="2024-07-14T05:23:16Z" level=info msg="generated new device id: 4735289c4ebe70f21e7ec3100480c6f09ac7cae7"
Jul 14 05:23:16 minione go-librespot[2450]: time="2024-07-14T05:23:16Z" level=debug msg="stored credentials not found"
Jul 14 05:23:17 minione go-librespot[2450]: time="2024-07-14T05:23:17Z" level=debug msg="obtained new client token: AAC5sP0WMiK89v9c8FYPzUmWYLsMbo04Q5sLWlF+qX5m6CbAyEL0I24Vz8To80EUZKaZXbOQbtiN1XMXH2zJeJHMGvV7C5Dg06Ot/jFeNNWLzrMHQelwAsleiqDuQiIGdFqlvlLZolBzuFcsAekG4aCTRdwE+7DuLYXN+9KKLofKzsYcAIwIJrn1VzLiaMFS23iJxupJLVfF7WckrxF80aWplIQ+m0eskZVx+y7yIhkpXGqhQhoKvxNHm7oo"
Jul 14 05:23:17 minione go-librespot[2450]: time="2024-07-14T05:23:17Z" 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]"
Jul 14 05:23:17 minione go-librespot[2450]: time="2024-07-14T05:23:17Z" level=debug msg="completed keyexchange"
Jul 14 05:23:18 minione go-librespot[2450]: time="2024-07-14T05:23:18Z" level=debug msg="completed challenge"
Jul 14 05:23:18 minione go-librespot[2450]: time="2024-07-14T05:23:18Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials"
Jul 14 05:23:18 minione systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 14 05:23:18 minione systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 14 05:23:19 minione volumio[627]: info: Initializing connection to go-librespot Websocket
Jul 14 05:23:19 minione volumio[627]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 14 05:23:21 minione systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 14 05:23:21 minione systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7756.
Jul 14 05:23:21 minione systemd[1]: Stopped go-librespot Daemon.
Jul 14 05:23:21 minione systemd[1]: Started go-librespot Daemon.
Jul 14 05:23:21 minione go-librespot[2459]: Librespot-go daemon starting...
Jul 14 05:23:21 minione go-librespot[2459]: time="2024-07-14T05:23:21Z" level=info msg="generated new device id: 68ee578938e9c261f15aa56c86013659adeccb7e"
Jul 14 05:23:21 minione go-librespot[2459]: time="2024-07-14T05:23:21Z" level=debug msg="stored credentials not found"
Jul 14 05:23:22 minione go-librespot[2459]: time="2024-07-14T05:23:22Z" level=debug msg="obtained new client token: AAD5IltcUtsISe+hPhTMtngGmOev/DtK0YpVnHywhXL+T7w2Qj5OAJeW9/P958gxMF4foZgsxONprOEWawPmeytk8jUtZXA4TsY85m3wKWMfFqYjtK60dzB3hwItSTnYCyyd8g5UEVPvi002KOaWth/n2oLimIgOWgcrToYtPITWd50bp8ztY6en6NUPYO9/f/2ELZWvFXviP+Jq92yVFiDm0N36N0ahxz/KGwSK3AziU253k3CJmiahfg=="
Jul 14 05:23:22 minione volumio[627]: info: Initializing connection to go-librespot Websocket
Jul 14 05:23:22 minione go-librespot[2459]: time="2024-07-14T05:23:22Z" level=debug msg="new websocket client"
Jul 14 05:23:22 minione volumio[627]: info: Connection to go-librespot Websocket established
Jul 14 05:23:22 minione go-librespot[2459]: time="2024-07-14T05:23:22Z" 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]"
Jul 14 05:23:22 minione winbindd[681]: [2024/07/14 05:23:22.726610,  0] ../source3/lib/util_tdb.c:316(tdb_log)
Jul 14 05:23:22 minione winbindd[681]:   tdb(/var/lib/samba/winbindd_cache.tdb): tdb_oob len 171192904 beyond eof at 32768
Jul 14 05:23:22 minione winbindd[681]: [2024/07/14 05:23:22.727306,  0] ../source3/lib/util_tdb.c:316(tdb_log)
Jul 14 05:23:22 minione winbindd[681]:   tdb(/var/lib/samba/winbindd_cache.tdb): tdb_oob len 171192904 beyond eof at 32768
Jul 14 05:23:22 minione winbindd[681]: [2024/07/14 05:23:22.727566,  0] ../source3/lib/util_tdb.c:316(tdb_log)
Jul 14 05:23:22 minione winbindd[681]:   tdb(/var/lib/samba/winbindd_cache.tdb): tdb_transaction_recover: failed to read recovery record
Jul 14 05:23:22 minione go-librespot[2459]: time="2024-07-14T05:23:22Z" level=debug msg="completed keyexchange"
Jul 14 05:23:23 minione go-librespot[2459]: time="2024-07-14T05:23:23Z" level=debug msg="completed challenge"
Jul 14 05:23:23 minione go-librespot[2459]: time="2024-07-14T05:23:23Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials"
Jul 14 05:23:23 minione systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 14 05:23:23 minione systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 14 05:23:23 minione volumio[627]: info: Connection to go-librespot Websocket closed
Jul 14 05:23:25 minione volumio[627]: info: Getting Spotify volume
Jul 14 05:23:25 minione volumio[627]: (node:627) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 14 05:23:25 minione volumio[627]:     at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16)
Jul 14 05:23:25 minione volumio[627]: (node:627) 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: 2913)
Jul 14 05:23:25 minione volumio[627]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7
Jul 14 05:23:25 minione volumio[627]: info: CoreCommandRouter::volumioGetState
Jul 14 05:23:25 minione volumio[627]: info: CorePlayQueue::getTrack 0
Jul 14 05:23:25 minione volumio[627]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60
Jul 14 05:23:26 minione volumio[627]: info: Initializing connection to go-librespot Websocket
Jul 14 05:23:26 minione volumio[627]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 14 05:23:26 minione systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 14 05:23:26 minione systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7757.
Jul 14 05:23:26 minione systemd[1]: Stopped go-librespot Daemon.
Jul 14 05:23:26 minione systemd[1]: Started go-librespot Daemon.
Jul 14 05:23:26 minione go-librespot[2469]: Librespot-go daemon starting...
Jul 14 05:23:26 minione go-librespot[2469]: time="2024-07-14T05:23:26Z" level=info msg="generated new device id: 1e6c15f7ae241054dd5b347665e10105c3cc6a5e"
Jul 14 05:23:26 minione go-librespot[2469]: time="2024-07-14T05:23:26Z" level=debug msg="stored credentials not found"
Jul 14 05:23:27 minione go-librespot[2469]: time="2024-07-14T05:23:27Z" level=debug msg="obtained new client token: AADBAK5l57iXtU2HfFOzMXZgQNQ9ePd3QredmKKhiYaa8fWlgnw9L/5SNZkQ1z+dQUGphBl6yd3esX3AktbE7axupNS2cq2wQwWMKc8Fr6cM0OqTRsmZgyWrU7RQX0FjXxjjO8+ycD00iLkgs6gaFt2Ae57TEmf59G8YratrTMFAJ5jPLA2gl8JvFKZyO/y/8JW8x59eKMN6PpVuoImdJ5mk3RoSNppuXMR7tMGlm80Mtd5mOP9fWkJHEdXy"
Jul 14 05:23:27 minione go-librespot[2469]: time="2024-07-14T05:23:27Z" 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]"
Jul 14 05:23:27 minione go-librespot[2469]: time="2024-07-14T05:23:27Z" level=debug msg="completed keyexchange"
Jul 14 05:23:28 minione go-librespot[2469]: time="2024-07-14T05:23:28Z" level=debug msg="completed challenge"
Jul 14 05:23:28 minione go-librespot[2469]: time="2024-07-14T05:23:28Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials"
Jul 14 05:23:28 minione systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 14 05:23:28 minione systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 14 05:23:28 minione volumio[627]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Jul 14 05:23:29 minione volumio[627]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled
Jul 14 05:23:29 minione volumio-remote-updater[427]: No test mode
Jul 14 05:23:29 minione volumio-remote-updater[427]: No alpha test mode
Jul 14 05:23:29 minione volumio[627]: info: Initializing connection to go-librespot Websocket
Jul 14 05:23:29 minione volumio[627]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Jul 14 05:23:30 minione kernel: EXT4-fs (mmcblk0p3): Delayed block allocation failed for inode 130888 at logical offset 0 with max blocks 1 with error 117
Jul 14 05:23:30 minione kernel: EXT4-fs (mmcblk0p3): This should not happen!! Data will be lost
Jul 14 05:23:30 minione volumio[627]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"FIXES
\n\nFix for missing library after reboot with slow USB devices
\n
\nNEW ADDITIONS
\n\nImprovements for MPD service
\nAdd Album title to playlist, queue and play next
\n\n","title":"Update v3.703","updateavailable":true}
Jul 14 05:23:30 minione volumio[627]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Jul 14 05:23:30 minione volumio[627]: SyntaxError: /data/configuration/plugins.json: Unexpected end of JSON input
Jul 14 05:23:30 minione volumio[627]:     at JSON.parse ()
Jul 14 05:23:30 minione volumio[627]:     at Object.readFileSync (/volumio/node_modules/jsonfile/index.js:69:17)
Jul 14 05:23:30 minione volumio[627]:     at PluginManager.getAllPlugNames (/volumio/app/pluginmanager.js:568:21)
Jul 14 05:23:30 minione volumio[627]:     at PluginManager.getPluginsMatrix (/volumio/app/pluginmanager.js:592:26)
Jul 14 05:23:30 minione volumio[627]:     at PluginManager.listPluginsBrokenByNewVersion (/volumio/app/pluginmanager.js:1224:22)
Jul 14 05:23:30 minione volumio[627]:     at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:934:60)
Jul 14 05:23:30 minione volumio[627]:     at Socket.emit (events.js:315:20)
Jul 14 05:23:30 minione volumio[627]:     at /volumio/node_modules/socket.io/lib/socket.js:503:12
Jul 14 05:23:30 minione volumio[627]:     at processTicksAndRejections (internal/process/task_queues.js:75:11)
Jul 14 05:23:30 minione volumio[627]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Jul 14 05:23:31 minione systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 14 05:23:31 minione systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7758.
Jul 14 05:23:31 minione systemd[1]: Stopped go-librespot Daemon.
Jul 14 05:23:31 minione systemd[1]: Started go-librespot Daemon.
Jul 14 05:23:31 minione go-librespot[2489]: Librespot-go daemon starting...
Jul 14 05:23:31 minione go-librespot[2489]: time="2024-07-14T05:23:31Z" level=info msg="generated new device id: a1c8925b2030469de05e6b7b8e903d58f7e09a76"
Jul 14 05:23:31 minione go-librespot[2489]: time="2024-07-14T05:23:31Z" level=debug msg="stored credentials not found"
Jul 14 05:23:32 minione go-librespot[2489]: time="2024-07-14T05:23:32Z" level=debug msg="obtained new client token: AACZNTBawqBoiyL2CkAg0p9l08PDY3l/BsWCw+0314g5mRfstHgp9negw7iS2yrnpWf+CFrjmvqKEaGk5QLEkv+Q2vWEGJmZIvM1NWtZy769wqRsoIg4O/koi56vfPYCFZoX2BJfuJZ24okax8XPHJR46I9BIHaiWL0fSBtycKnn+hRYNG5hvApknuJQf3NSHOSTJcX0hI4kk4cQZZa3QuDwtxAYgnuVMisI8NsuGDonCvVM/eIBuoB2xEOh"
Jul 14 05:23:32 minione go-librespot[2489]: time="2024-07-14T05:23:32Z" 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]"
Jul 14 05:23:33 minione go-librespot[2489]: time="2024-07-14T05:23:33Z" level=debug msg="completed keyexchange"
Jul 14 05:23:33 minione sudo[2499]:  volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-07-14 05:22
Jul 14 05:23:33 minione sudo[2499]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 14 05:23:33 minione go-librespot[2489]: time="2024-07-14T05:23:33Z" level=debug msg="completed challenge"
Jul 14 05:23:33 minione go-librespot[2489]: time="2024-07-14T05:23:33Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials"
Jul 14 05:23:33 minione systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 14 05:23:33 minione systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
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="cd8cf34b47ce852e70b71e6f7b6e0265f7fdb695"
VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71"
VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1"
VOLUMIO_BE_VERSION="8f88153f9a18f312d56050e6613b45a852ac819a"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Wed 27 Sep 2023 11:35:49 AM CEST"
VOLUMIO_VERSION="3.546"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="6823c0d83061ff736b7e0dd4481bc496"