-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Mon 2025-01-13 21:39:26 CET. -- Jan 13 21:38:00 volumio volumio[927]: info: Getting Spotify volume Jan 13 21:38:00 volumio volumio[927]: (node:927) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 13 21:38:00 volumio volumio[927]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jan 13 21:38:00 volumio volumio[927]: (node:927) 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: 52) Jan 13 21:38:00 volumio volumio[927]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Jan 13 21:38:00 volumio volumio[927]: info: CoreCommandRouter::volumioGetState Jan 13 21:38:00 volumio volumio[927]: info: CorePlayQueue::getTrack 2425 Jan 13 21:38:00 volumio volumio[927]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 Jan 13 21:38:01 volumio volumio[927]: info: Initializing connection to go-librespot Websocket Jan 13 21:38:01 volumio volumio[927]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 13 21:38:01 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 13 21:38:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 152. Jan 13 21:38:01 volumio systemd[1]: Stopped go-librespot Daemon. Jan 13 21:38:01 volumio systemd[1]: Started go-librespot Daemon. Jan 13 21:38:01 volumio go-librespot[4745]: Librespot-go daemon starting... Jan 13 21:38:01 volumio go-librespot[4745]: time="2025-01-13T21:38:01+01:00" level=info msg="generated new device id: 8e2fecdbaf343d68514b42521c737d9b49a4fde8" Jan 13 21:38:01 volumio go-librespot[4745]: time="2025-01-13T21:38:01+01:00" level=debug msg="stored credentials found for 1fvz1" Jan 13 21:38:01 volumio go-librespot[4745]: time="2025-01-13T21:38:01+01:00" level=debug msg="obtained new client token: AABzX7efneZCU7dtMH4AYSxkGEHDrrm1N7YQRJiGjSVSIBxfnb/eyNhvUv49sPSqV0E+UeKrd7n6dhKp+MXw6CmG1NwZ3pgiN/fgdxnBzup+qoXyjb6eEtInRBoIwx+mk45H2YFjCcda8Gaw1iIBrzr5PB4F/cW0MpfhemW0KwAo1xbKeEgb7QpcY/XOGEikESe9RIcrJ3M/WdHxo50ZU30qkyuN0REPsTNxodIvWxfwHEeN5fC+hTFSp6Rnjy6R" Jan 13 21:38:01 volumio go-librespot[4745]: time="2025-01-13T21:38:01+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jan 13 21:38:02 volumio go-librespot[4745]: time="2025-01-13T21:38:02+01:00" level=debug msg="completed keyexchange" Jan 13 21:38:02 volumio go-librespot[4745]: time="2025-01-13T21:38:02+01:00" level=debug msg="completed challenge" Jan 13 21:38:02 volumio go-librespot[4745]: time="2025-01-13T21:38:02+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jan 13 21:38:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 21:38:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 21:38:04 volumio volumio[927]: info: Initializing connection to go-librespot Websocket Jan 13 21:38:04 volumio volumio[927]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 13 21:38:05 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 13 21:38:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 153. Jan 13 21:38:05 volumio systemd[1]: Stopped go-librespot Daemon. Jan 13 21:38:05 volumio systemd[1]: Started go-librespot Daemon. Jan 13 21:38:05 volumio go-librespot[4754]: Librespot-go daemon starting... Jan 13 21:38:05 volumio go-librespot[4754]: time="2025-01-13T21:38:05+01:00" level=info msg="generated new device id: 7d1804dd807c2c34ed93ed83e9bd4d5339b53b74" Jan 13 21:38:05 volumio go-librespot[4754]: time="2025-01-13T21:38:05+01:00" level=debug msg="stored credentials found for 1fvz1" Jan 13 21:38:06 volumio go-librespot[4754]: time="2025-01-13T21:38:06+01:00" level=debug msg="obtained new client token: AACXAvzoI3MgSmv38rdjuikd1hhlIofmXt1QSKVTcLQ+9IYPsThhgayTKZVGOUQMG6FJSIUxMH92PFgK7Cx/nOeOOjYs8u0h/HFhKltq3Qig0NfkpCpRwdG4sJRbPa7tIhqxqN+XElSIUtUEnmzzAa6jMjdk3vhsHkIthCXMLhbUzs7/ZhLSKU7mBnK9gvpX6Gd4ucWL7aYrjbMZwSlFbxDrHZIY1jSMVmyYfUeMPkDRKXTawuUJoLvaxkc=" Jan 13 21:38:06 volumio go-librespot[4754]: time="2025-01-13T21:38:06+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Jan 13 21:38:06 volumio go-librespot[4754]: time="2025-01-13T21:38:06+01:00" level=debug msg="completed keyexchange" Jan 13 21:38:06 volumio go-librespot[4754]: time="2025-01-13T21:38:06+01:00" level=debug msg="completed challenge" Jan 13 21:38:06 volumio go-librespot[4754]: time="2025-01-13T21:38:06+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jan 13 21:38:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 21:38:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 21:38:07 volumio volumio[927]: info: Initializing connection to go-librespot Websocket Jan 13 21:38:07 volumio volumio[927]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 13 21:38:09 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 13 21:38:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 154. Jan 13 21:38:09 volumio systemd[1]: Stopped go-librespot Daemon. Jan 13 21:38:09 volumio systemd[1]: Started go-librespot Daemon. Jan 13 21:38:09 volumio go-librespot[4779]: Librespot-go daemon starting... Jan 13 21:38:09 volumio go-librespot[4779]: time="2025-01-13T21:38:09+01:00" level=info msg="generated new device id: 3134e90ef6de94fa754da5c15f9e581d82c730df" Jan 13 21:38:09 volumio go-librespot[4779]: time="2025-01-13T21:38:09+01:00" level=debug msg="stored credentials found for 1fvz1" Jan 13 21:38:10 volumio go-librespot[4779]: time="2025-01-13T21:38:10+01:00" level=debug msg="obtained new client token: AACLSDY0UMurBvnjwRlFSoeKvg5OBHenAzmepzoCWGJsmS8hZxWznWmdEy5KHR3cYIM7gvuwO0ZLCDt1tuDIKoDynka/jr6PiOhMAw12oXyVRynV9ZjnPooLYYhnv5+agD9vXzFsPNKo6i02elywXYj/Fd4z1fhzlxN5vkS40kgJ6Yav7zBKQm1OrLywKp+JsQFxhpiibia7SDaWmrUMEsFC/ivnAMDGH0bSU4n0pp59x2RXDyLTSreGPL5GJQ==" Jan 13 21:38:10 volumio go-librespot[4779]: time="2025-01-13T21:38:10+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Jan 13 21:38:10 volumio volumio[927]: info: Initializing connection to go-librespot Websocket Jan 13 21:38:10 volumio go-librespot[4779]: time="2025-01-13T21:38:10+01:00" level=debug msg="new websocket client" Jan 13 21:38:10 volumio volumio[927]: info: Connection to go-librespot Websocket established Jan 13 21:38:10 volumio go-librespot[4779]: time="2025-01-13T21:38:10+01:00" level=debug msg="completed keyexchange" Jan 13 21:38:11 volumio go-librespot[4779]: time="2025-01-13T21:38:11+01:00" level=debug msg="completed challenge" Jan 13 21:38:11 volumio go-librespot[4779]: time="2025-01-13T21:38:11+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jan 13 21:38:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 21:38:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 21:38:11 volumio volumio[927]: info: Connection to go-librespot Websocket closed Jan 13 21:38:13 volumio volumio[927]: info: Getting Spotify volume Jan 13 21:38:13 volumio volumio[927]: (node:927) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 13 21:38:13 volumio volumio[927]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jan 13 21:38:13 volumio volumio[927]: (node:927) 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: 53) Jan 13 21:38:13 volumio volumio[927]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Jan 13 21:38:13 volumio volumio[927]: info: CoreCommandRouter::volumioGetState Jan 13 21:38:13 volumio volumio[927]: info: CorePlayQueue::getTrack 2425 Jan 13 21:38:13 volumio volumio[927]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 Jan 13 21:38:14 volumio volumio[927]: info: Initializing connection to go-librespot Websocket Jan 13 21:38:14 volumio volumio[927]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 13 21:38:14 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 13 21:38:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 155. Jan 13 21:38:14 volumio systemd[1]: Stopped go-librespot Daemon. Jan 13 21:38:14 volumio systemd[1]: Started go-librespot Daemon. Jan 13 21:38:14 volumio go-librespot[4790]: Librespot-go daemon starting... Jan 13 21:38:14 volumio go-librespot[4790]: time="2025-01-13T21:38:14+01:00" level=info msg="generated new device id: c8958b4c913381f85102fd64aab8bdbe6df80b89" Jan 13 21:38:14 volumio go-librespot[4790]: time="2025-01-13T21:38:14+01:00" level=debug msg="stored credentials found for 1fvz1" Jan 13 21:38:14 volumio go-librespot[4790]: time="2025-01-13T21:38:14+01:00" level=debug msg="obtained new client token: AABOeX5mjOmavfX1KkR7TtfYxW6e5nOCJTAPA7IymHVZxSS/6H94Ur2dvP85cn/ZHHYtpNnt2onOgXaYEWl8gsA49hjkXt7f1J6MUZ7fRo4VtncsMhwyCAxKO4Lc2P3U+0ReKHpT0KIE3qGcvUWqNxU64aUMpTX85LajCyEG8CxfGAiUJP/utFm69xV/1xvbmHPbB7KNmoTXVhMk3GrDw67484/IC9RWYsypBoddXCt8dwlTVy1k8IZ+mU1RVMLo" Jan 13 21:38:14 volumio go-librespot[4790]: time="2025-01-13T21:38:14+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 13 21:38:14 volumio go-librespot[4790]: time="2025-01-13T21:38:14+01:00" level=debug msg="completed keyexchange" Jan 13 21:38:15 volumio go-librespot[4790]: time="2025-01-13T21:38:15+01:00" level=debug msg="completed challenge" Jan 13 21:38:15 volumio go-librespot[4790]: time="2025-01-13T21:38:15+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jan 13 21:38:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 21:38:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 21:38:17 volumio volumio[927]: info: Initializing connection to go-librespot Websocket Jan 13 21:38:17 volumio volumio[927]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 13 21:38:18 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 13 21:38:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 156. Jan 13 21:38:18 volumio systemd[1]: Stopped go-librespot Daemon. Jan 13 21:38:18 volumio systemd[1]: Started go-librespot Daemon. Jan 13 21:38:18 volumio go-librespot[4811]: Librespot-go daemon starting... Jan 13 21:38:18 volumio go-librespot[4811]: time="2025-01-13T21:38:18+01:00" level=info msg="generated new device id: be041aa370850419b759fc511b947cbf9e2f9685" Jan 13 21:38:18 volumio go-librespot[4811]: time="2025-01-13T21:38:18+01:00" level=debug msg="stored credentials found for 1fvz1" Jan 13 21:38:18 volumio go-librespot[4811]: time="2025-01-13T21:38:18+01:00" level=debug msg="obtained new client token: AAB3mXQBkRLOjfCfKh/lYIfADX4vMlJVqkoHk+nR7c6GiE7O+KT/V7Ab+i5BS//Fu604tJUN9mgtp/ZCsHKVW6IpDHjKnkrx5dcfnLrEWHk4iIDPAi0wEpojZRluoVeaCwWF0q5qO/yfNpfk2xi8iATzym5bV8B0BY5q7BdGcHChkdHRISIZ/W17ngTzfga7FtEa3tNXYWiboGTSqQYLHyaMR/W7bzQS4m31IEdZzv4WVrItT+EogyuA4CjfnpiS" Jan 13 21:38:18 volumio go-librespot[4811]: time="2025-01-13T21:38:18+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 13 21:38:19 volumio go-librespot[4811]: time="2025-01-13T21:38:19+01:00" level=debug msg="completed keyexchange" Jan 13 21:38:19 volumio go-librespot[4811]: time="2025-01-13T21:38:19+01:00" level=debug msg="completed challenge" Jan 13 21:38:19 volumio go-librespot[4811]: time="2025-01-13T21:38:19+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jan 13 21:38:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 21:38:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 21:38:20 volumio volumio[927]: info: Initializing connection to go-librespot Websocket Jan 13 21:38:20 volumio volumio[927]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 13 21:38:22 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 13 21:38:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 157. Jan 13 21:38:22 volumio systemd[1]: Stopped go-librespot Daemon. Jan 13 21:38:22 volumio systemd[1]: Started go-librespot Daemon. Jan 13 21:38:22 volumio go-librespot[4827]: Librespot-go daemon starting... Jan 13 21:38:22 volumio go-librespot[4827]: time="2025-01-13T21:38:22+01:00" level=info msg="generated new device id: 6d2d8d5c418b2b3421bf99bca19b66adaa98b4a6" Jan 13 21:38:22 volumio go-librespot[4827]: time="2025-01-13T21:38:22+01:00" level=debug msg="stored credentials found for 1fvz1" Jan 13 21:38:23 volumio go-librespot[4827]: time="2025-01-13T21:38:23+01:00" level=debug msg="obtained new client token: AADo0295stubKuGCXuTZ0p2BnFoYAli8uQXls+0Icjfy0KtmsxD451w3HnlF1SOkXUPW/WjDJGpbu1QxalTmqziHklv5cMjKbk9Ce0FAJnruua0iaGR0pb5H4TEUoqmfc0ivN39xyGQ0zbhl9oVWeUiaMxDq28OB4GuYzKYJC8bbaoP49F3Rb4/t5jRroAeNNNuWDTBtLrowU6iOphEofX8YcNMsHSRxPXcVJI7Hf8A9/qI6YkK11lr4+r6qqw==" Jan 13 21:38:23 volumio volumio[927]: info: Initializing connection to go-librespot Websocket Jan 13 21:38:23 volumio go-librespot[4827]: time="2025-01-13T21:38:23+01:00" level=debug msg="new websocket client" Jan 13 21:38:23 volumio volumio[927]: info: Connection to go-librespot Websocket established Jan 13 21:38:23 volumio go-librespot[4827]: time="2025-01-13T21:38:23+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jan 13 21:38:23 volumio go-librespot[4827]: time="2025-01-13T21:38:23+01:00" level=debug msg="completed keyexchange" Jan 13 21:38:23 volumio go-librespot[4827]: time="2025-01-13T21:38:23+01:00" level=debug msg="completed challenge" Jan 13 21:38:23 volumio go-librespot[4827]: time="2025-01-13T21:38:23+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jan 13 21:38:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 21:38:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 21:38:23 volumio volumio[927]: info: Connection to go-librespot Websocket closed Jan 13 21:38:26 volumio volumio[927]: info: Getting Spotify volume Jan 13 21:38:26 volumio volumio[927]: (node:927) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 13 21:38:26 volumio volumio[927]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jan 13 21:38:26 volumio volumio[927]: (node:927) 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: 54) Jan 13 21:38:26 volumio volumio[927]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Jan 13 21:38:26 volumio volumio[927]: info: CoreCommandRouter::volumioGetState Jan 13 21:38:26 volumio volumio[927]: info: CorePlayQueue::getTrack 2425 Jan 13 21:38:26 volumio volumio[927]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 Jan 13 21:38:26 volumio volumio[927]: info: Initializing connection to go-librespot Websocket Jan 13 21:38:26 volumio volumio[927]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 13 21:38:26 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 13 21:38:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 158. Jan 13 21:38:26 volumio systemd[1]: Stopped go-librespot Daemon. Jan 13 21:38:26 volumio systemd[1]: Started go-librespot Daemon. Jan 13 21:38:26 volumio go-librespot[4835]: Librespot-go daemon starting... Jan 13 21:38:27 volumio go-librespot[4835]: time="2025-01-13T21:38:27+01:00" level=info msg="generated new device id: eaf82ece07a7aeb76cb4972f82732418c84145a7" Jan 13 21:38:27 volumio go-librespot[4835]: time="2025-01-13T21:38:27+01:00" level=debug msg="stored credentials found for 1fvz1" Jan 13 21:38:27 volumio go-librespot[4835]: time="2025-01-13T21:38:27+01:00" level=debug msg="obtained new client token: AABJCVwPAsa4PblVxWb9BkosWSN1PUvoFsFXMI4cb1dNmm7QciT3N9Phg5VrPtjkohQ7CgQb5qU15pG/gtcs7Hw2AdZQUF1NoLk3Gdk/9DU5/4SG8Z8y5PqwJ1MxpTPf0JNE1CiXHOcVKcztpUVlVpkRIuvay6vG3poW7HGD3MJpfj6aK8R4DISg9FJ6h6shdw44iVS5COGhzQsT1TGchQjerfdX/8kKijgYRY9ZeakbGZ7QmAraVEV/peRb5w==" Jan 13 21:38:27 volumio go-librespot[4835]: time="2025-01-13T21:38:27+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 13 21:38:27 volumio go-librespot[4835]: time="2025-01-13T21:38:27+01:00" level=debug msg="completed keyexchange" Jan 13 21:38:28 volumio go-librespot[4835]: time="2025-01-13T21:38:28+01:00" level=debug msg="completed challenge" Jan 13 21:38:28 volumio go-librespot[4835]: time="2025-01-13T21:38:28+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jan 13 21:38:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 21:38:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 21:38:29 volumio volumio[927]: info: Initializing connection to go-librespot Websocket Jan 13 21:38:29 volumio volumio[927]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 13 21:38:31 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 13 21:38:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 159. Jan 13 21:38:31 volumio systemd[1]: Stopped go-librespot Daemon. Jan 13 21:38:31 volumio systemd[1]: Started go-librespot Daemon. Jan 13 21:38:31 volumio go-librespot[4860]: Librespot-go daemon starting... Jan 13 21:38:31 volumio go-librespot[4860]: time="2025-01-13T21:38:31+01:00" level=info msg="generated new device id: 71fccd7a4a1dca877e4f496f135db2ce701a9f8c" Jan 13 21:38:31 volumio go-librespot[4860]: time="2025-01-13T21:38:31+01:00" level=debug msg="stored credentials found for 1fvz1" Jan 13 21:38:31 volumio go-librespot[4860]: time="2025-01-13T21:38:31+01:00" level=debug msg="obtained new client token: AAA7cW9e/BwqEf4CFj/vM2wVbzYONp5SRgPiaebndGwxXwaFuCHFcbaoD0A9E56YDqcs6P4E3ffAR4NEDvDp2ug81lG1VaMEXpwq1ar9hA3VTeLH0QSPu8I0JMQDOw7yPaj+fWpGQ/Utci+y/Bws6beeVSJ48zryt/nVvYSB+HYp7EFAkIUv87WODf73gTahc2l+67uq2BOj7r1FW0YjiKgVASfaN7KuJ0+LlhNf6WvQmGyjTd6S7CRbN0CgQIE7" Jan 13 21:38:31 volumio go-librespot[4860]: time="2025-01-13T21:38:31+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 13 21:38:31 volumio go-librespot[4860]: time="2025-01-13T21:38:31+01:00" level=debug msg="completed keyexchange" Jan 13 21:38:32 volumio go-librespot[4860]: time="2025-01-13T21:38:32+01:00" level=debug msg="completed challenge" Jan 13 21:38:32 volumio go-librespot[4860]: time="2025-01-13T21:38:32+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jan 13 21:38:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 21:38:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 21:38:32 volumio volumio[927]: info: Initializing connection to go-librespot Websocket Jan 13 21:38:32 volumio volumio[927]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 13 21:38:35 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 13 21:38:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 160. Jan 13 21:38:35 volumio systemd[1]: Stopped go-librespot Daemon. Jan 13 21:38:35 volumio systemd[1]: Started go-librespot Daemon. Jan 13 21:38:35 volumio go-librespot[4868]: Librespot-go daemon starting... Jan 13 21:38:35 volumio go-librespot[4868]: time="2025-01-13T21:38:35+01:00" level=info msg="generated new device id: d4b1957ccab3f3e898c8bc138eba00b348f32fd9" Jan 13 21:38:35 volumio go-librespot[4868]: time="2025-01-13T21:38:35+01:00" level=debug msg="stored credentials found for 1fvz1" Jan 13 21:38:35 volumio go-librespot[4868]: time="2025-01-13T21:38:35+01:00" level=debug msg="obtained new client token: AABxi4+FafZwhTGHI0+U4GaKxzl8+RXTBVIScw2rpjyCYYoMPm3BFC0LmwJIsjN0XUz5NNOYDTeR92w6Ii5xg59Njt3n69wbppVEIBGhTvStUCRBhcW9sPeVHz9P3WnZhV6cFFNKPjU3Aok/XuRzRm6L12pX3dfmG3w78bPGNvJ/a3A+KucZoLhQMebVZBsqffwcvO9S0ENZ3m1206lyNBdY17ml0GR5LxWyXxmdnglq7Q0uABnxKdsZyAzGpJ4H" Jan 13 21:38:35 volumio volumio[927]: info: Initializing connection to go-librespot Websocket Jan 13 21:38:35 volumio go-librespot[4868]: time="2025-01-13T21:38:35+01:00" level=debug msg="new websocket client" Jan 13 21:38:35 volumio volumio[927]: info: Connection to go-librespot Websocket established Jan 13 21:38:35 volumio go-librespot[4868]: time="2025-01-13T21:38:35+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jan 13 21:38:36 volumio go-librespot[4868]: time="2025-01-13T21:38:36+01:00" level=debug msg="completed keyexchange" Jan 13 21:38:36 volumio go-librespot[4868]: time="2025-01-13T21:38:36+01:00" level=debug msg="completed challenge" Jan 13 21:38:36 volumio go-librespot[4868]: time="2025-01-13T21:38:36+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jan 13 21:38:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 21:38:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 21:38:36 volumio volumio[927]: info: Connection to go-librespot Websocket closed Jan 13 21:38:38 volumio volumio[927]: info: Getting Spotify volume Jan 13 21:38:38 volumio volumio[927]: (node:927) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 13 21:38:38 volumio volumio[927]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jan 13 21:38:38 volumio volumio[927]: (node:927) 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: 55) Jan 13 21:38:38 volumio volumio[927]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Jan 13 21:38:38 volumio volumio[927]: info: CoreCommandRouter::volumioGetState Jan 13 21:38:38 volumio volumio[927]: info: CorePlayQueue::getTrack 2425 Jan 13 21:38:38 volumio volumio[927]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 Jan 13 21:38:39 volumio volumio[927]: info: Initializing connection to go-librespot Websocket Jan 13 21:38:39 volumio volumio[927]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 13 21:38:39 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 13 21:38:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 161. Jan 13 21:38:39 volumio systemd[1]: Stopped go-librespot Daemon. Jan 13 21:38:39 volumio systemd[1]: Started go-librespot Daemon. Jan 13 21:38:39 volumio go-librespot[4891]: Librespot-go daemon starting... Jan 13 21:38:39 volumio go-librespot[4891]: time="2025-01-13T21:38:39+01:00" level=info msg="generated new device id: 49dde6be038506ca534ae68a80248bda03b2b565" Jan 13 21:38:39 volumio go-librespot[4891]: time="2025-01-13T21:38:39+01:00" level=debug msg="stored credentials found for 1fvz1" Jan 13 21:38:40 volumio go-librespot[4891]: time="2025-01-13T21:38:40+01:00" level=debug msg="obtained new client token: AAC+sOB2zywnh+N+bMfjRlyWpuHthO5H94l/IpO2gUNBZJewBaA36ReYeXKOne0VsTTipmPCE9xdgnXbmRyDIKEIvapqmiqEm1e4EbbCwhbMiH5f2RHNKKYlUu/fTvXMYI+ILN7nzDhDAq5ihzI3DdgCaEB7DFY2X9UCV7OTnfBEbhFMvvtIKegMJB111RKJqEgLKokB7CYKQTChasuiXlDpBScdUjjcA05bB/160byo3f4hNog1R+GB6cFRDg==" Jan 13 21:38:40 volumio go-librespot[4891]: time="2025-01-13T21:38:40+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 13 21:38:40 volumio go-librespot[4891]: time="2025-01-13T21:38:40+01:00" level=debug msg="completed keyexchange" Jan 13 21:38:40 volumio go-librespot[4891]: time="2025-01-13T21:38:40+01:00" level=debug msg="completed challenge" Jan 13 21:38:40 volumio go-librespot[4891]: time="2025-01-13T21:38:40+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jan 13 21:38:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 21:38:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 21:38:42 volumio volumio[927]: info: Initializing connection to go-librespot Websocket Jan 13 21:38:42 volumio volumio[927]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 13 21:38:43 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 13 21:38:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 162. Jan 13 21:38:43 volumio systemd[1]: Stopped go-librespot Daemon. Jan 13 21:38:43 volumio systemd[1]: Started go-librespot Daemon. Jan 13 21:38:43 volumio go-librespot[4944]: Librespot-go daemon starting... Jan 13 21:38:44 volumio go-librespot[4944]: time="2025-01-13T21:38:44+01:00" level=info msg="generated new device id: d8d8c7ec9ccaec052d85c6559d2eba782e4363be" Jan 13 21:38:44 volumio go-librespot[4944]: time="2025-01-13T21:38:44+01:00" level=debug msg="stored credentials found for 1fvz1" Jan 13 21:38:44 volumio go-librespot[4944]: time="2025-01-13T21:38:44+01:00" level=debug msg="obtained new client token: AABeMsxbXUR831wWNSVHE5rzy9lUnAIjXT10WV+xDDgPjKJD9e+qKsaZBAQcqngAnYxg0Xnpx19n5NJmHyS3/lV6SfC6MkNWkM5RXYby+cyQseRgZpLMZalE9Y0e+a60gpgLXRwG18IaCJ9Uk/IzbZ5yhxfG+054RrzdWv6Bui9Pay/SiZsus+kK2ZEspded52bxhWhOh5xArnyuuADCsN7rROW+9Aer0686Ph7qdVTDFztBUY0BZZ7ljxVSjw==" Jan 13 21:38:44 volumio go-librespot[4944]: time="2025-01-13T21:38:44+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Jan 13 21:38:44 volumio go-librespot[4944]: time="2025-01-13T21:38:44+01:00" level=debug msg="completed keyexchange" Jan 13 21:38:45 volumio go-librespot[4944]: time="2025-01-13T21:38:45+01:00" level=debug msg="completed challenge" Jan 13 21:38:45 volumio go-librespot[4944]: time="2025-01-13T21:38:45+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jan 13 21:38:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 21:38:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 21:38:45 volumio volumio[927]: info: Initializing connection to go-librespot Websocket Jan 13 21:38:45 volumio volumio[927]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 13 21:38:48 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 13 21:38:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 163. Jan 13 21:38:48 volumio systemd[1]: Stopped go-librespot Daemon. Jan 13 21:38:48 volumio systemd[1]: Started go-librespot Daemon. Jan 13 21:38:48 volumio go-librespot[4952]: Librespot-go daemon starting... Jan 13 21:38:48 volumio go-librespot[4952]: time="2025-01-13T21:38:48+01:00" level=info msg="generated new device id: 200895a162f121ba440845d7e172f9d7999ce7e5" Jan 13 21:38:48 volumio go-librespot[4952]: time="2025-01-13T21:38:48+01:00" level=debug msg="stored credentials found for 1fvz1" Jan 13 21:38:48 volumio volumio[927]: info: Initializing connection to go-librespot Websocket Jan 13 21:38:48 volumio go-librespot[4952]: time="2025-01-13T21:38:48+01:00" level=debug msg="new websocket client" Jan 13 21:38:48 volumio volumio[927]: info: Connection to go-librespot Websocket established Jan 13 21:38:51 volumio volumio[927]: info: Getting Spotify volume Jan 13 21:38:51 volumio volumio[927]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Jan 13 21:38:51 volumio volumio[927]: info: CoreCommandRouter::volumioGetState Jan 13 21:38:51 volumio volumio[927]: info: CorePlayQueue::getTrack 2425 Jan 13 21:38:51 volumio volumio[927]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 Jan 13 21:39:25 volumio volumio[927]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 13 21:39:25 volumio volumio[927]: Error: getaddrinfo ENOTFOUND ws.audioscrobbler.com Jan 13 21:39:25 volumio volumio[927]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Jan 13 21:39:25 volumio volumio[927]: errno: -3007, Jan 13 21:39:25 volumio volumio[927]: code: 'ENOTFOUND', Jan 13 21:39:25 volumio volumio[927]: syscall: 'getaddrinfo', Jan 13 21:39:25 volumio volumio[927]: hostname: 'ws.audioscrobbler.com' Jan 13 21:39:25 volumio volumio[927]: } Jan 13 21:39:25 volumio volumio[927]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 13 21:39:26 volumio sudo[5043]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-01-13 21:38 Jan 13 21:39:26 volumio sudo[5043]: 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="f6610a1100d2380eef33bd3004af43153c786f96" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="1c0e5daee99fe3a72cc38b0d1fe6cd78d7f001fe" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 16 Dec 2024 09:30:04 AM CET" VOLUMIO_VERSION="3.785" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fe0ac4b79aed19ccde4b5bd83d468193"