-- Logs begin at Sun 2024-09-08 20:10:01 BST, end at Sun 2024-09-08 21:26:16 BST. -- Sep 08 21:25:00 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 08 21:25:00 minidsp-shd volumio[724]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 08 21:25:03 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 08 21:25:03 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1001. Sep 08 21:25:03 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 08 21:25:03 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 08 21:25:03 minidsp-shd go-librespot[21395]: Librespot-go daemon starting... Sep 08 21:25:03 minidsp-shd go-librespot[21395]: time="2024-09-08T21:25:03+01:00" level=info msg="generated new device id: 95a9887433bb1d123fb7d10dc5f8b8eb9098f648" Sep 08 21:25:03 minidsp-shd go-librespot[21395]: time="2024-09-08T21:25:03+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 08 21:25:03 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 08 21:25:03 minidsp-shd go-librespot[21395]: time="2024-09-08T21:25:03+01:00" level=debug msg="new websocket client" Sep 08 21:25:03 minidsp-shd volumio[724]: info: Connection to go-librespot Websocket established Sep 08 21:25:03 minidsp-shd go-librespot[21395]: time="2024-09-08T21:25:03+01:00" level=debug msg="obtained new client token: AABK0XgXmrFZchHXaVQAt0F7gIBI81vMXWww+7PL8BEGYUGC/+a9ot/et5qYwopPSPM8niZb2WC+i5w1b3Qv4Tr5rJv5AA0AYWkULybe4Mvt3L40dXBtUIlE1LuNim75HWCPdnMEX1/vGYtDURtZVXjFWkF8mOXRqfSJ7HlI0avL5STR3IzmRhLOck+ryhP7cE/GOFYIEM3o3n94yApEwT6VNfm9n8Xa9/azwzCubXxJgEg+oPNhtnj2BLY3Wxg=" Sep 08 21:25:03 minidsp-shd go-librespot[21395]: time="2024-09-08T21:25:03+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-gue1.spotify.com:4070 ap2-gew4.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 08 21:25:03 minidsp-shd go-librespot[21395]: time="2024-09-08T21:25:03+01:00" level=debug msg="completed keyexchange" Sep 08 21:25:04 minidsp-shd go-librespot[21395]: time="2024-09-08T21:25:04+01:00" level=debug msg="completed challenge" Sep 08 21:25:04 minidsp-shd go-librespot[21395]: time="2024-09-08T21:25:04+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 08 21:25:04 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 08 21:25:04 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 08 21:25:04 minidsp-shd volumio[724]: info: Connection to go-librespot Websocket closed Sep 08 21:25:06 minidsp-shd volumio[724]: info: Getting Spotify volume Sep 08 21:25:06 minidsp-shd volumio[724]: (node:724) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 08 21:25:06 minidsp-shd volumio[724]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Sep 08 21:25:06 minidsp-shd volumio[724]: (node:724) 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: 310) Sep 08 21:25:06 minidsp-shd volumio[724]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 8 Sep 08 21:25:06 minidsp-shd volumio[724]: info: CoreCommandRouter::volumioGetState Sep 08 21:25:06 minidsp-shd volumio[724]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 Sep 08 21:25:07 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 08 21:25:07 minidsp-shd volumio[724]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 08 21:25:07 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 08 21:25:07 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1002. Sep 08 21:25:07 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 08 21:25:07 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 08 21:25:07 minidsp-shd go-librespot[21411]: Librespot-go daemon starting... Sep 08 21:25:07 minidsp-shd go-librespot[21411]: time="2024-09-08T21:25:07+01:00" level=info msg="generated new device id: 8cb9aa6f3b8871b80e9b73eb13d400e9c8fdca1c" Sep 08 21:25:07 minidsp-shd go-librespot[21411]: time="2024-09-08T21:25:07+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 08 21:25:07 minidsp-shd go-librespot[21411]: time="2024-09-08T21:25:07+01:00" level=debug msg="obtained new client token: AAA7tXWy9NvH7S2c9deeKaCqGA7SkvlkhkX7anro5Brn6/hOoafq1xkk34/O7LSfdqcMOZQMoeIqrXD/ZuihtJUYq1TFWU1wUj+9haAVs/5/RM1i++IZyzuJRLiXHXZ89IGYJBHQndZnMCPa30zKd89OZFgkHkq8sAF2K8190uVZPN20rSf9iy0hPhp99lghldsQJznX9FXA3RBHQFg7eoiMViXxw4xLDak5eaWWJ6PFDNvbZyRbf0SCS4Z5Zw8=" Sep 08 21:25:07 minidsp-shd go-librespot[21411]: time="2024-09-08T21:25:07+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-guc3.spotify.com:4070 ap2-gue1.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 08 21:25:07 minidsp-shd go-librespot[21411]: time="2024-09-08T21:25:07+01:00" level=debug msg="completed keyexchange" Sep 08 21:25:08 minidsp-shd go-librespot[21411]: time="2024-09-08T21:25:08+01:00" level=debug msg="completed challenge" Sep 08 21:25:08 minidsp-shd go-librespot[21411]: time="2024-09-08T21:25:08+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 08 21:25:08 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 08 21:25:08 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 08 21:25:10 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 08 21:25:10 minidsp-shd volumio[724]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 08 21:25:11 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 08 21:25:11 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1003. Sep 08 21:25:11 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 08 21:25:11 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 08 21:25:11 minidsp-shd go-librespot[21428]: Librespot-go daemon starting... Sep 08 21:25:11 minidsp-shd go-librespot[21428]: time="2024-09-08T21:25:11+01:00" level=info msg="generated new device id: dfd78f2fa47d538680d89362535757d703e8fdf1" Sep 08 21:25:11 minidsp-shd go-librespot[21428]: time="2024-09-08T21:25:11+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 08 21:25:11 minidsp-shd go-librespot[21428]: time="2024-09-08T21:25:11+01:00" level=debug msg="obtained new client token: AADnGx2UgyQQfzn2CN1TquvToHOQFXHBNlmdpGkJ0NoXphwq34JGxtuovFMfnRJKZhOIvB1JJG9z5BHj3005efd6UvRJHrJWRyio08gTOupD1MsplYqpWzCU8m/GfgyZYPEOcmTZYw5acc9nTOmY3oMSmA+Bs4IhJE59+n0oI0XwpdUTywmfJcwNvePlOA4sA/13UzLYt4xlOVU/+3A+2uUmWVw5JpJW3hxke2Pp9pvB9CIH2oWzVmHMDHOKC8g=" Sep 08 21:25:11 minidsp-shd go-librespot[21428]: time="2024-09-08T21:25:11+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-gue1.spotify.com:4070 ap2-gew4.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 08 21:25:11 minidsp-shd go-librespot[21428]: time="2024-09-08T21:25:11+01:00" level=debug msg="completed keyexchange" Sep 08 21:25:12 minidsp-shd go-librespot[21428]: time="2024-09-08T21:25:12+01:00" level=debug msg="completed challenge" Sep 08 21:25:12 minidsp-shd go-librespot[21428]: time="2024-09-08T21:25:12+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 08 21:25:12 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 08 21:25:12 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 08 21:25:13 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 08 21:25:13 minidsp-shd volumio[724]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 08 21:25:15 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 08 21:25:15 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1004. Sep 08 21:25:15 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 08 21:25:15 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 08 21:25:15 minidsp-shd go-librespot[21444]: Librespot-go daemon starting... Sep 08 21:25:15 minidsp-shd go-librespot[21444]: time="2024-09-08T21:25:15+01:00" level=info msg="generated new device id: ba88e9ef3f6966ad1a374f0d7d4bdcdd5655f10b" Sep 08 21:25:15 minidsp-shd go-librespot[21444]: time="2024-09-08T21:25:15+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 08 21:25:15 minidsp-shd go-librespot[21444]: time="2024-09-08T21:25:15+01:00" level=debug msg="obtained new client token: AAC4WxPCyPRs0+UtFfBY/CY1NfkSZRE93bUdIgMIwCHjrOKQDeGgD3QWQAJGaRXxC4ahULywuxS7LPmBejnO6VeMJuGrkTxeuuLRBnV7oD8Xt7I3zhROA517SHP6GnyHahdIR4MPC6bHF4SdcpDIma1jtW3cbyA7t4N6Qlz3jAkm/3JGr4dOuHbLWv7V1Imrufl5oQ+Vr0SkPjAd5xUSebauF3pYFEJ9Ztm+OCVOxztZkU5CcZYKjBCewi0jeFs=" Sep 08 21:25:15 minidsp-shd go-librespot[21444]: time="2024-09-08T21:25:15+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-gue1.spotify.com:4070 ap2-gew4.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 08 21:25:15 minidsp-shd go-librespot[21444]: time="2024-09-08T21:25:15+01:00" level=debug msg="completed keyexchange" Sep 08 21:25:16 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 08 21:25:16 minidsp-shd go-librespot[21444]: time="2024-09-08T21:25:16+01:00" level=debug msg="new websocket client" Sep 08 21:25:16 minidsp-shd volumio[724]: info: Connection to go-librespot Websocket established Sep 08 21:25:16 minidsp-shd go-librespot[21444]: time="2024-09-08T21:25:16+01:00" level=debug msg="completed challenge" Sep 08 21:25:16 minidsp-shd go-librespot[21444]: time="2024-09-08T21:25:16+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 08 21:25:16 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 08 21:25:16 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 08 21:25:16 minidsp-shd volumio[724]: info: Connection to go-librespot Websocket closed Sep 08 21:25:19 minidsp-shd volumio[724]: info: Getting Spotify volume Sep 08 21:25:19 minidsp-shd volumio[724]: (node:724) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 08 21:25:19 minidsp-shd volumio[724]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Sep 08 21:25:19 minidsp-shd volumio[724]: (node:724) 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: 311) Sep 08 21:25:19 minidsp-shd volumio[724]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 8 Sep 08 21:25:19 minidsp-shd volumio[724]: info: CoreCommandRouter::volumioGetState Sep 08 21:25:19 minidsp-shd volumio[724]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 Sep 08 21:25:19 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 08 21:25:19 minidsp-shd volumio[724]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 08 21:25:19 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 08 21:25:19 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1005. Sep 08 21:25:19 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 08 21:25:19 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 08 21:25:19 minidsp-shd go-librespot[21460]: Librespot-go daemon starting... Sep 08 21:25:19 minidsp-shd go-librespot[21460]: time="2024-09-08T21:25:19+01:00" level=info msg="generated new device id: d6e1eda89a572d0a87428c5120c60d1802ccd490" Sep 08 21:25:19 minidsp-shd go-librespot[21460]: time="2024-09-08T21:25:19+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 08 21:25:19 minidsp-shd go-librespot[21460]: time="2024-09-08T21:25:19+01:00" level=debug msg="obtained new client token: AADcwpP34FG4Tn7KsIwmysn9kPKH2xpXZkMR6pFfn12WU/oPUfjUs3WyaTEjv370iQpzHTQM78ZxoP2j+J9whg+CmrMAYOaNBwySfxJD3KIfbIKk1Kh4Sw4D2Ect5/rqMOmN/hU4VIomSQao9s1j7XQPY1iutXtfMFsxqT11CGwxqXu8Mw3ruJAAGjbucydCg7iJhz/H4D3TOOA5/3aHtXMdRSTX2BkQJKtphPcBZjfwo0odMavxWnamvJGR904=" Sep 08 21:25:20 minidsp-shd go-librespot[21460]: time="2024-09-08T21:25:20+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-gue1.spotify.com:4070 ap2-gew4.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 08 21:25:20 minidsp-shd go-librespot[21460]: time="2024-09-08T21:25:20+01:00" level=debug msg="completed keyexchange" Sep 08 21:25:20 minidsp-shd go-librespot[21460]: time="2024-09-08T21:25:20+01:00" level=debug msg="completed challenge" Sep 08 21:25:20 minidsp-shd go-librespot[21460]: time="2024-09-08T21:25:20+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 08 21:25:20 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 08 21:25:20 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 08 21:25:22 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 08 21:25:22 minidsp-shd volumio[724]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 08 21:25:23 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 08 21:25:23 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1006. Sep 08 21:25:23 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 08 21:25:23 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 08 21:25:23 minidsp-shd go-librespot[21476]: Librespot-go daemon starting... Sep 08 21:25:23 minidsp-shd go-librespot[21476]: time="2024-09-08T21:25:23+01:00" level=info msg="generated new device id: b50cbb9b7536105d399a98cbdd482b8aa51255f1" Sep 08 21:25:23 minidsp-shd go-librespot[21476]: time="2024-09-08T21:25:23+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 08 21:25:24 minidsp-shd go-librespot[21476]: time="2024-09-08T21:25:24+01:00" level=debug msg="obtained new client token: AAC1q5UVMKioaO3tDFV4OiteAs/Ju6tgNXhAdwGKLcp/Qvq2PLipqibYPwK2HsqlnmwHuxZHvJA6DdRYjs9PMzyYZcNuDGwiO/wrbDA9LMcyq6ezGRypJY1vfnvUgFoDyVql0JFlIMOE8UksyH8wjnoXAbK1repDMRkU7t1419Xlml8KBN8fKOAjauDGJp62jP2u2JAY/EcZP6/JB7jDoCMJZw3naho8AW35snzG8MxRwfBRAj2SSDNZWAzH" Sep 08 21:25:24 minidsp-shd go-librespot[21476]: time="2024-09-08T21:25:24+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-guc3.spotify.com:4070 ap2-gue1.spotify.com:443 ap2-gew4.spotify.com:80]" Sep 08 21:25:24 minidsp-shd go-librespot[21476]: time="2024-09-08T21:25:24+01:00" level=debug msg="completed keyexchange" Sep 08 21:25:24 minidsp-shd go-librespot[21476]: time="2024-09-08T21:25:24+01:00" level=debug msg="completed challenge" Sep 08 21:25:24 minidsp-shd go-librespot[21476]: time="2024-09-08T21:25:24+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 08 21:25:24 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 08 21:25:24 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 08 21:25:25 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 08 21:25:25 minidsp-shd volumio[724]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 08 21:25:28 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 08 21:25:28 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1007. Sep 08 21:25:28 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 08 21:25:28 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 08 21:25:28 minidsp-shd go-librespot[21492]: Librespot-go daemon starting... Sep 08 21:25:28 minidsp-shd go-librespot[21492]: time="2024-09-08T21:25:28+01:00" level=info msg="generated new device id: 13859e45c846f05742da4d5c56897516d73f33c3" Sep 08 21:25:28 minidsp-shd go-librespot[21492]: time="2024-09-08T21:25:28+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 08 21:25:28 minidsp-shd go-librespot[21492]: time="2024-09-08T21:25:28+01:00" level=debug msg="obtained new client token: AABqqOHJbzHUzeqhfgjHoNUurW+Lk7sF7fqlsFXmpxKcAC1aE7Vt5ZspOQEnBVgHKYhXINlCfhVb33IucdLFYyydxyDdRSVsyKGFmpxW2kT3q+D/X9xUATwEcBFBMJ0Y83hbip+gIXuVncXc/oiOkBB+y0BtHaz0RtOuEYtIbNxxLyasP2ibG0ogWO7b+G4UCMCLCmsHMQiPIgcGGVKFA0XdH+GJRwbKwsSrOJGadLno4mVqGbuPf6n+lQeM1XI=" Sep 08 21:25:28 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 08 21:25:28 minidsp-shd volumio[724]: info: Connection to go-librespot Websocket established Sep 08 21:25:28 minidsp-shd go-librespot[21492]: time="2024-09-08T21:25:28+01:00" level=debug msg="new websocket client" Sep 08 21:25:28 minidsp-shd go-librespot[21492]: time="2024-09-08T21:25:28+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-guc3.spotify.com:4070 ap2-gue1.spotify.com:443 ap2-gew4.spotify.com:80]" Sep 08 21:25:28 minidsp-shd go-librespot[21492]: time="2024-09-08T21:25:28+01:00" level=debug msg="completed keyexchange" Sep 08 21:25:29 minidsp-shd go-librespot[21492]: time="2024-09-08T21:25:29+01:00" level=debug msg="completed challenge" Sep 08 21:25:29 minidsp-shd go-librespot[21492]: time="2024-09-08T21:25:29+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 08 21:25:29 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 08 21:25:29 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 08 21:25:29 minidsp-shd volumio[724]: info: Connection to go-librespot Websocket closed Sep 08 21:25:31 minidsp-shd volumio[724]: info: Getting Spotify volume Sep 08 21:25:31 minidsp-shd volumio[724]: (node:724) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 08 21:25:31 minidsp-shd volumio[724]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Sep 08 21:25:31 minidsp-shd volumio[724]: (node:724) 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: 312) Sep 08 21:25:31 minidsp-shd volumio[724]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 8 Sep 08 21:25:31 minidsp-shd volumio[724]: info: CoreCommandRouter::volumioGetState Sep 08 21:25:31 minidsp-shd volumio[724]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 Sep 08 21:25:32 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 08 21:25:32 minidsp-shd volumio[724]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 08 21:25:32 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 08 21:25:32 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1008. Sep 08 21:25:32 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 08 21:25:32 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 08 21:25:32 minidsp-shd go-librespot[21510]: Librespot-go daemon starting... Sep 08 21:25:32 minidsp-shd go-librespot[21510]: time="2024-09-08T21:25:32+01:00" level=info msg="generated new device id: 95788b63e547972759c6d64d673ae29e928f98e4" Sep 08 21:25:32 minidsp-shd go-librespot[21510]: time="2024-09-08T21:25:32+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 08 21:25:32 minidsp-shd go-librespot[21510]: time="2024-09-08T21:25:32+01:00" level=debug msg="obtained new client token: AAAItZC7dF6GkaDPh5zKMaTJGZ5Do8awkF1Xs+GwJXC1i1rYUCsrAXxBWKBMJ7QaTQvHI4l5DuW+kBy9sdgpJ1wcBek0d3fXTYcHoe7SFC7WaCqJmeB+0R5EnwQLrqEtdQ4PCy4KFU1zsRu0EsNQs/xQDCqbfDeQLjKjj+Mv0o5JnW3OaWPbfIDFhHe+Zb/phe6rHq/PPf34U6U9cf62zlbG/Hr/RWQjCZx2k8cIQoZiYrCAp6Q4MwSzKKdefnw=" Sep 08 21:25:32 minidsp-shd go-librespot[21510]: time="2024-09-08T21:25:32+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-guc3.spotify.com:4070 ap2-gue1.spotify.com:443 ap2-gew4.spotify.com:80]" Sep 08 21:25:32 minidsp-shd go-librespot[21510]: time="2024-09-08T21:25:32+01:00" level=debug msg="completed keyexchange" Sep 08 21:25:33 minidsp-shd go-librespot[21510]: time="2024-09-08T21:25:33+01:00" level=debug msg="completed challenge" Sep 08 21:25:33 minidsp-shd go-librespot[21510]: time="2024-09-08T21:25:33+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 08 21:25:33 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 08 21:25:33 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 08 21:25:35 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 08 21:25:35 minidsp-shd volumio[724]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 08 21:25:36 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 08 21:25:36 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1009. Sep 08 21:25:36 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 08 21:25:36 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 08 21:25:36 minidsp-shd go-librespot[21528]: Librespot-go daemon starting... Sep 08 21:25:36 minidsp-shd go-librespot[21528]: time="2024-09-08T21:25:36+01:00" level=info msg="generated new device id: 820ff5c7ee7c56a4b2cfb57e51d8b5c1061c8eec" Sep 08 21:25:36 minidsp-shd go-librespot[21528]: time="2024-09-08T21:25:36+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 08 21:25:36 minidsp-shd go-librespot[21528]: time="2024-09-08T21:25:36+01:00" level=debug msg="obtained new client token: AAB0JxFSe8yDlyxwuw/5yo0FX+Ip9FL8B0ALFdWX1cnozEWGmsqzQFzYAr1usdvEzZlxGKNphlt/vAzCStUa9xaDEO1+OH0FK39d1Ae6eZq0jYNDoQhiZXCSqS1QEMA56xa3KUExfcnDKuG4MD0TqCIz4yNbHa0rqBQFbuVy+qPhBJKl/4ZPwuT/FVID8Vnyt5hneHJ7CXjjx2LiLxE2JIEr2wbROazSQQepcV7/X0jml70TvrV0M0PzTkTiau4=" Sep 08 21:25:37 minidsp-shd go-librespot[21528]: time="2024-09-08T21:25:37+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-guc3.spotify.com:4070 ap2-gew4.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 08 21:25:37 minidsp-shd go-librespot[21528]: time="2024-09-08T21:25:37+01:00" level=debug msg="completed keyexchange" Sep 08 21:25:37 minidsp-shd go-librespot[21528]: time="2024-09-08T21:25:37+01:00" level=debug msg="completed challenge" Sep 08 21:25:37 minidsp-shd go-librespot[21528]: time="2024-09-08T21:25:37+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 08 21:25:37 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 08 21:25:37 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 08 21:25:38 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 08 21:25:38 minidsp-shd volumio[724]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 08 21:25:40 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 08 21:25:40 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1010. Sep 08 21:25:40 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 08 21:25:40 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 08 21:25:40 minidsp-shd go-librespot[21544]: Librespot-go daemon starting... Sep 08 21:25:40 minidsp-shd go-librespot[21544]: time="2024-09-08T21:25:40+01:00" level=info msg="generated new device id: a8c6b7a3f8a6f7e0c0413d53a904d5c82781ee15" Sep 08 21:25:40 minidsp-shd go-librespot[21544]: time="2024-09-08T21:25:40+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 08 21:25:41 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 08 21:25:41 minidsp-shd go-librespot[21544]: time="2024-09-08T21:25:41+01:00" level=debug msg="new websocket client" Sep 08 21:25:41 minidsp-shd volumio[724]: info: Connection to go-librespot Websocket established Sep 08 21:25:41 minidsp-shd go-librespot[21544]: time="2024-09-08T21:25:41+01:00" level=debug msg="obtained new client token: AACXnBJOKX2xlZt86R8vfoOh5o29ILPJxp27Hi7U31J6RmNKPVByAMa2VSIVoCXIcBB+FO4Th1Y8bk8BTcw3CmaZYrBhhQvf0F4FGl7UBr0ZMhVzvHoDGA7KwAspRrNDoLAFX54GoQ+hJiIGwR7+X1lYn+Z0mGU3dQ+j2Bd3YeAH8ofuYdDmYveD5npkxKRvhtQwV3iA5FsaqbGwllIH7O+u53bwP5kBetq4JuGrbjJ9vjf/9ohNlA+wOSbh" Sep 08 21:25:41 minidsp-shd go-librespot[21544]: time="2024-09-08T21:25:41+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-guc3.spotify.com:4070 ap2-gue1.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 08 21:25:41 minidsp-shd go-librespot[21544]: time="2024-09-08T21:25:41+01:00" level=debug msg="completed keyexchange" Sep 08 21:25:41 minidsp-shd go-librespot[21544]: time="2024-09-08T21:25:41+01:00" level=debug msg="completed challenge" Sep 08 21:25:41 minidsp-shd go-librespot[21544]: time="2024-09-08T21:25:41+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 08 21:25:41 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 08 21:25:41 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 08 21:25:41 minidsp-shd volumio[724]: info: Connection to go-librespot Websocket closed Sep 08 21:25:44 minidsp-shd volumio[724]: info: Getting Spotify volume Sep 08 21:25:44 minidsp-shd volumio[724]: (node:724) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 08 21:25:44 minidsp-shd volumio[724]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Sep 08 21:25:44 minidsp-shd volumio[724]: (node:724) 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: 313) Sep 08 21:25:44 minidsp-shd volumio[724]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 Sep 08 21:25:44 minidsp-shd volumio[724]: info: CoreCommandRouter::volumioGetState Sep 08 21:25:44 minidsp-shd volumio[724]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 Sep 08 21:25:44 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 08 21:25:44 minidsp-shd volumio[724]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 08 21:25:45 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 08 21:25:45 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1011. Sep 08 21:25:45 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 08 21:25:45 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 08 21:25:45 minidsp-shd go-librespot[21560]: Librespot-go daemon starting... Sep 08 21:25:45 minidsp-shd go-librespot[21560]: time="2024-09-08T21:25:45+01:00" level=info msg="generated new device id: 19dc50899a2006061998d064e42ae239a28a5d2b" Sep 08 21:25:45 minidsp-shd go-librespot[21560]: time="2024-09-08T21:25:45+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 08 21:25:45 minidsp-shd go-librespot[21560]: time="2024-09-08T21:25:45+01:00" level=debug msg="obtained new client token: AACHp7PR+CEyyV5EqPXfb/jcUrTrBhq3RkHC2KwkgW65hTMu8Yv8DO1nIobXZjxpK3E7TfA1B2X4z4O0QbiXk3GudAfy8qw0q0aarUzKeyJGCt6bgzpL9NOXmWAocSp7pLoNSTsixgEUYDZLKNbGnhh5PQIW9M7wQ2tPyDtTMTg93Z+fedZD2OSxpKZE7nGmwGXXUMyE897eIh3ZV4Ri0iS/y8rwN/0Kxc5ozh6R9UQvCm5m57DwppXAQX1HUSI=" Sep 08 21:25:45 minidsp-shd go-librespot[21560]: time="2024-09-08T21:25:45+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-guc3.spotify.com:4070 ap2-gew4.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 08 21:25:45 minidsp-shd go-librespot[21560]: time="2024-09-08T21:25:45+01:00" level=debug msg="completed keyexchange" Sep 08 21:25:46 minidsp-shd go-librespot[21560]: time="2024-09-08T21:25:46+01:00" level=debug msg="completed challenge" Sep 08 21:25:46 minidsp-shd go-librespot[21560]: time="2024-09-08T21:25:46+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 08 21:25:46 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 08 21:25:46 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 08 21:25:47 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 08 21:25:47 minidsp-shd volumio[724]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 08 21:25:49 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 08 21:25:49 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1012. Sep 08 21:25:49 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 08 21:25:49 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 08 21:25:49 minidsp-shd go-librespot[21577]: Librespot-go daemon starting... Sep 08 21:25:49 minidsp-shd go-librespot[21577]: time="2024-09-08T21:25:49+01:00" level=info msg="generated new device id: ca64e5553afbcee7d551865d0531543d78d306dc" Sep 08 21:25:49 minidsp-shd go-librespot[21577]: time="2024-09-08T21:25:49+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 08 21:25:49 minidsp-shd go-librespot[21577]: time="2024-09-08T21:25:49+01:00" level=debug msg="obtained new client token: AABrDer4ew1Kr2dvZzp18wCw49lQX+5xVEkeA8fEQ/rz/gxP2/PhyDVb1MpNC/8p2Y+INJD3uaOfzKjEtXoBpMsw6MBzuoJcjj6fet5nHpJH0vDZQ8ErCzHEWfd2ZZ7WyuTYJxl2/9qGz2Xb3LNCIUXlvkm/lA6EZEP82zBU0dhaO+hqizKr+pJDokPwhi0aiPGx48HaeLhsjnBqzhtH1z5jdK0SVLxcTSA9pEalQvZr+2oBP4mioto+2sOLZ4E=" Sep 08 21:25:49 minidsp-shd go-librespot[21577]: time="2024-09-08T21:25:49+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-guc3.spotify.com:4070 ap2-gew4.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 08 21:25:49 minidsp-shd go-librespot[21577]: time="2024-09-08T21:25:49+01:00" level=debug msg="completed keyexchange" Sep 08 21:25:50 minidsp-shd go-librespot[21577]: time="2024-09-08T21:25:50+01:00" level=debug msg="completed challenge" Sep 08 21:25:50 minidsp-shd go-librespot[21577]: time="2024-09-08T21:25:50+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 08 21:25:50 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 08 21:25:50 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 08 21:25:50 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 08 21:25:50 minidsp-shd volumio[724]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 08 21:25:53 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 08 21:25:53 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1013. Sep 08 21:25:53 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 08 21:25:53 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 08 21:25:53 minidsp-shd go-librespot[21631]: Librespot-go daemon starting... Sep 08 21:25:53 minidsp-shd go-librespot[21631]: time="2024-09-08T21:25:53+01:00" level=info msg="generated new device id: 1fdac8d4e5e7fae11af307bfbce57344ae48e8f1" Sep 08 21:25:53 minidsp-shd go-librespot[21631]: time="2024-09-08T21:25:53+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 08 21:25:53 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 08 21:25:53 minidsp-shd go-librespot[21631]: time="2024-09-08T21:25:53+01:00" level=debug msg="new websocket client" Sep 08 21:25:53 minidsp-shd volumio[724]: info: Connection to go-librespot Websocket established Sep 08 21:25:53 minidsp-shd go-librespot[21631]: time="2024-09-08T21:25:53+01:00" level=debug msg="obtained new client token: AADhxhgyuhtiBLMAXTMj3iYq4BBwpKu2LivIJ2lj1L7r5ytJ+3+gR/i64Ne49wQDBfWal6LiFKLTKynCClcLc9NR5LgqgX962mJMkC7eU657DkiNzQJnKMFBgf61Vxucp2PuGKcYrBK0WnW8aV/mu4rJTkOfqeBIv2GpcqoVgSDIalGa53wmDDfqIunSxPrWYiFb4BI+fylhq+he7klewEriQAvm/BVgU29ZmpJKY/Kvs9E9esQzUH6npc0F8cc=" Sep 08 21:25:54 minidsp-shd go-librespot[21631]: time="2024-09-08T21:25:54+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-guc3.spotify.com:4070 ap2-gew4.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 08 21:25:54 minidsp-shd go-librespot[21631]: time="2024-09-08T21:25:54+01:00" level=debug msg="completed keyexchange" Sep 08 21:25:54 minidsp-shd go-librespot[21631]: time="2024-09-08T21:25:54+01:00" level=debug msg="completed challenge" Sep 08 21:25:54 minidsp-shd go-librespot[21631]: time="2024-09-08T21:25:54+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 08 21:25:54 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 08 21:25:54 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 08 21:25:54 minidsp-shd volumio[724]: info: Connection to go-librespot Websocket closed Sep 08 21:25:56 minidsp-shd volumio[724]: info: Getting Spotify volume Sep 08 21:25:56 minidsp-shd volumio[724]: (node:724) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 08 21:25:56 minidsp-shd volumio[724]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Sep 08 21:25:56 minidsp-shd volumio[724]: (node:724) 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: 314) Sep 08 21:25:56 minidsp-shd volumio[724]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 Sep 08 21:25:57 minidsp-shd volumio[724]: info: CoreCommandRouter::volumioGetState Sep 08 21:25:57 minidsp-shd volumio[724]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 Sep 08 21:25:57 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 08 21:25:57 minidsp-shd volumio[724]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 08 21:25:57 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 08 21:25:57 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1014. Sep 08 21:25:57 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 08 21:25:57 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 08 21:25:57 minidsp-shd go-librespot[21647]: Librespot-go daemon starting... Sep 08 21:25:57 minidsp-shd go-librespot[21647]: time="2024-09-08T21:25:57+01:00" level=info msg="generated new device id: 16d0c16986750fe79c78f926b6853460fe78b15b" Sep 08 21:25:57 minidsp-shd go-librespot[21647]: time="2024-09-08T21:25:57+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 08 21:25:58 minidsp-shd go-librespot[21647]: time="2024-09-08T21:25:58+01:00" level=debug msg="obtained new client token: AADXRcs8SRQF3pcn+zemWYo440bbsmvqCmzGbwlIu4hwRfEwum8INBjI0JX8VOsrMK6Gtbn9kKV9AZCxRzBkoaz6yV1/Z9PmneaCY1lsamrbr6ByII0Y7cqhk+K2bhBKTNmic6uDNwDhotEkPiemejDI4rqwCC/+jlAfmbQgHwF3nQCPmgpXEjgZDPoxuFYrrLWGGMBcI/tugpEByZQdDkbC+CFyODuN6/LJ6gggJ5ZsyJ5BXXf94PmtVZbX" Sep 08 21:25:58 minidsp-shd go-librespot[21647]: time="2024-09-08T21:25:58+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-gue1.spotify.com:4070 ap2-gew4.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 08 21:25:58 minidsp-shd go-librespot[21647]: time="2024-09-08T21:25:58+01:00" level=debug msg="completed keyexchange" Sep 08 21:25:59 minidsp-shd go-librespot[21647]: time="2024-09-08T21:25:59+01:00" level=debug msg="completed challenge" Sep 08 21:25:59 minidsp-shd go-librespot[21647]: time="2024-09-08T21:25:59+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 08 21:25:59 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 08 21:25:59 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 08 21:26:00 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 08 21:26:00 minidsp-shd volumio[724]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 08 21:26:02 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 08 21:26:02 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1015. Sep 08 21:26:02 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 08 21:26:02 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 08 21:26:02 minidsp-shd go-librespot[21665]: Librespot-go daemon starting... Sep 08 21:26:02 minidsp-shd go-librespot[21665]: time="2024-09-08T21:26:02+01:00" level=info msg="generated new device id: 90e453e3421594c6c1c9f347e327365aac1c06ff" Sep 08 21:26:02 minidsp-shd go-librespot[21665]: time="2024-09-08T21:26:02+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 08 21:26:02 minidsp-shd go-librespot[21665]: time="2024-09-08T21:26:02+01:00" level=debug msg="obtained new client token: AACJZ5Y0f8QqcWqwdOBtfaCQVGyf9iyT2iMYxaPLPjOF2bhJt0UQbZ8Tkd/95xZd3KVB28WdjDJxsqAsUcIu1YFuMd6Q9z+lldhHAwaPHncTi+KIm7mgLOGweIxVcCj1u93iZH+4yQiVENwo0OM8yL4D1aMfB1yP/A43FmJgeFSw/GU7N4oMFKlN5diKnkbgMsGfHJBX5iq5dCtNI7KSnfCfB5Mg7Sa5/nQgDdxgaVl5P0I/XG2kKUexcn9UaaE=" Sep 08 21:26:02 minidsp-shd go-librespot[21665]: time="2024-09-08T21:26:02+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-gue1.spotify.com:4070 ap2-gew4.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 08 21:26:02 minidsp-shd go-librespot[21665]: time="2024-09-08T21:26:02+01:00" level=debug msg="completed keyexchange" Sep 08 21:26:03 minidsp-shd go-librespot[21665]: time="2024-09-08T21:26:03+01:00" level=debug msg="completed challenge" Sep 08 21:26:03 minidsp-shd go-librespot[21665]: time="2024-09-08T21:26:03+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 08 21:26:03 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 08 21:26:03 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 08 21:26:03 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 08 21:26:03 minidsp-shd volumio[724]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 08 21:26:06 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 08 21:26:06 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1016. Sep 08 21:26:06 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 08 21:26:06 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 08 21:26:06 minidsp-shd go-librespot[21681]: Librespot-go daemon starting... Sep 08 21:26:06 minidsp-shd go-librespot[21681]: time="2024-09-08T21:26:06+01:00" level=info msg="generated new device id: b97115d31af8827eb606a53c4b3efd494c32a767" Sep 08 21:26:06 minidsp-shd go-librespot[21681]: time="2024-09-08T21:26:06+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 08 21:26:06 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 08 21:26:06 minidsp-shd go-librespot[21681]: time="2024-09-08T21:26:06+01:00" level=debug msg="new websocket client" Sep 08 21:26:06 minidsp-shd go-librespot[21681]: time="2024-09-08T21:26:06+01:00" level=debug msg="obtained new client token: AAChfMWXJVeEfAebiTSxKG1WsNjB2l95Mixi6yyLe/3xlIQCBmqv/TEM80EgngV7QMje8iy8vhpF585kQjXu+Tu6RtrC0PcxVECssisTcjVc95p0rK1py5f6kDCUXo1wpdrAPfGK13P4HmwnPSbcw2peIeQ3UxZRRNYWGsJGtanvrxIuujxM0Coz6Zc9jmy6IBm6TG/TSH+gamFJ6ChRDXgDAV91B393AYGsLOD7EDDqbu1bREdxe/RhbqvEYxk=" Sep 08 21:26:06 minidsp-shd volumio[724]: info: Connection to go-librespot Websocket established Sep 08 21:26:06 minidsp-shd go-librespot[21681]: time="2024-09-08T21:26:06+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-guc3.spotify.com:4070 ap2-gue1.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 08 21:26:06 minidsp-shd go-librespot[21681]: time="2024-09-08T21:26:06+01:00" level=debug msg="completed keyexchange" Sep 08 21:26:07 minidsp-shd go-librespot[21681]: time="2024-09-08T21:26:07+01:00" level=debug msg="completed challenge" Sep 08 21:26:07 minidsp-shd go-librespot[21681]: time="2024-09-08T21:26:07+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 08 21:26:07 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 08 21:26:07 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 08 21:26:07 minidsp-shd volumio[724]: info: Connection to go-librespot Websocket closed Sep 08 21:26:09 minidsp-shd volumio[724]: info: CorePlayQueue::getTrack 35 Sep 08 21:26:09 minidsp-shd volumio[724]: info: CorePlayQueue::getTrack 36 Sep 08 21:26:09 minidsp-shd volumio[724]: verbose: New Socket.io Connection to 192.168.1.210 from 192.168.1.93 UA: unknown Total Clients: 7 Sep 08 21:26:09 minidsp-shd volumio[724]: info: Getting Spotify volume Sep 08 21:26:09 minidsp-shd volumio[724]: info: CoreCommandRouter::volumioGetState Sep 08 21:26:09 minidsp-shd volumio[724]: (node:724) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 08 21:26:09 minidsp-shd volumio[724]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Sep 08 21:26:09 minidsp-shd volumio[724]: (node:724) 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: 315) Sep 08 21:26:09 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Sep 08 21:26:09 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Sep 08 21:26:09 minidsp-shd volumio[724]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 8 Sep 08 21:26:09 minidsp-shd volumio[724]: info: CoreCommandRouter::volumioGetState Sep 08 21:26:09 minidsp-shd volumio[724]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 Sep 08 21:26:10 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 08 21:26:10 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 08 21:26:10 minidsp-shd volumio[724]: info: Discovery: Getting this device information Sep 08 21:26:10 minidsp-shd volumio[724]: info: CoreCommandRouter::volumioGetState Sep 08 21:26:10 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 08 21:26:10 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 08 21:26:10 minidsp-shd volumio[724]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 08 21:26:10 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 08 21:26:10 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1017. Sep 08 21:26:10 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 08 21:26:10 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 08 21:26:10 minidsp-shd go-librespot[21700]: Librespot-go daemon starting... Sep 08 21:26:10 minidsp-shd go-librespot[21700]: time="2024-09-08T21:26:10+01:00" level=info msg="generated new device id: e825d1fe0357f7196ee19db49580d1a537e980a2" Sep 08 21:26:10 minidsp-shd go-librespot[21700]: time="2024-09-08T21:26:10+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 08 21:26:10 minidsp-shd go-librespot[21700]: time="2024-09-08T21:26:10+01:00" level=debug msg="obtained new client token: AACxo9nSODkE8TBL/gpJIjBDg0jc+kzoM34dGCIVx313rGuKMMxjlKgfbVreh5uOH8B33vu7euwu2dde287F7KySL5ec1NG9GSnYOj+RxYRxRzQA/WeamDBdn4QWtih+qsVpnaR7rfYm8BYwS5BjrWF7D9Yb31Cl53sPhdf7hEDqrnFOdDb5mLkEHF7Sek/BUsDyZd9G9fKBCMxmLusFeTK/KBjKjRJ1ikR22qh4ps6IXe1h70hGvWoZNTDt6AY=" Sep 08 21:26:11 minidsp-shd go-librespot[21700]: time="2024-09-08T21:26:11+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-gue1.spotify.com:4070 ap2-gew4.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 08 21:26:11 minidsp-shd volumio[724]: verbose: New Socket.io Connection to 192.168.1.210 from 192.168.1.93 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Total Clients: 8 Sep 08 21:26:11 minidsp-shd go-librespot[21700]: time="2024-09-08T21:26:11+01:00" level=debug msg="completed keyexchange" Sep 08 21:26:12 minidsp-shd go-librespot[21700]: time="2024-09-08T21:26:12+01:00" level=debug msg="completed challenge" Sep 08 21:26:12 minidsp-shd go-librespot[21700]: time="2024-09-08T21:26:12+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 08 21:26:12 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 08 21:26:12 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 08 21:26:12 minidsp-shd sudo[21713]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 08 21:26:12 minidsp-shd sudo[21713]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 21:26:12 minidsp-shd sudo[21713]: pam_unix(sudo:session): session closed for user root Sep 08 21:26:12 minidsp-shd sudo[21716]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 08 21:26:12 minidsp-shd sudo[21716]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 21:26:12 minidsp-shd sudo[21716]: pam_unix(sudo:session): session closed for user root Sep 08 21:26:12 minidsp-shd volumio[724]: verbose: New Socket.io Connection to 192.168.1.210 from 192.168.1.93 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Total Clients: 9 Sep 08 21:26:12 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Sep 08 21:26:12 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Sep 08 21:26:12 minidsp-shd volumio[724]: info: CoreCommandRouter::volumioGetVisibleSources Sep 08 21:26:12 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 08 21:26:12 minidsp-shd volumio[724]: info: CoreCommandRouter::volumioGetState Sep 08 21:26:12 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Sep 08 21:26:12 minidsp-shd volumio[724]: info: CoreCommandRouter::volumioGetQueue Sep 08 21:26:12 minidsp-shd volumio[724]: info: CoreStateMachine::getQueue Sep 08 21:26:12 minidsp-shd volumio[724]: info: CorePlayQueue::getQueue Sep 08 21:26:12 minidsp-shd volumio[724]: info: Listing playlists Sep 08 21:26:12 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Sep 08 21:26:12 minidsp-shd volumio[724]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Sep 08 21:26:12 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: inputs , handleBrowseUri Sep 08 21:26:12 minidsp-shd volumio[724]: info: Received Get System Info Sep 08 21:26:12 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 08 21:26:12 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 08 21:26:12 minidsp-shd volumio[724]: info: Discovery: Getting this device information Sep 08 21:26:12 minidsp-shd volumio[724]: info: CoreCommandRouter::volumioGetState Sep 08 21:26:12 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 08 21:26:12 minidsp-shd volumio[724]: info: CoreCommandRouter::volumioGetState Sep 08 21:26:12 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Sep 08 21:26:12 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Sep 08 21:26:13 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Sep 08 21:26:13 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 08 21:26:13 minidsp-shd volumio[724]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 08 21:26:14 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 08 21:26:14 minidsp-shd volumio[724]: info: Received Get System Info Sep 08 21:26:14 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 08 21:26:14 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 08 21:26:14 minidsp-shd volumio[724]: info: Discovery: Getting this device information Sep 08 21:26:14 minidsp-shd volumio[724]: info: CoreCommandRouter::volumioGetState Sep 08 21:26:14 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 08 21:26:15 minidsp-shd volumio[724]: info: Sep 08 21:26:15 minidsp-shd volumio[724]: ---------------------------- MPD announces state update: player Sep 08 21:26:15 minidsp-shd volumio[724]: info: ControllerMpd::getState Sep 08 21:26:15 minidsp-shd volumio[724]: verbose: ControllerMpd::sendMpdCommand status Sep 08 21:26:15 minidsp-shd volumio[724]: info: Sep 08 21:26:15 minidsp-shd volumio[724]: ---------------------------- MPD announces state update: player Sep 08 21:26:15 minidsp-shd volumio[724]: info: ControllerMpd::getState Sep 08 21:26:15 minidsp-shd volumio[724]: verbose: ControllerMpd::sendMpdCommand status Sep 08 21:26:15 minidsp-shd volumio[724]: info: Sep 08 21:26:15 minidsp-shd volumio[724]: ---------------------------- MPD announces state update: player Sep 08 21:26:15 minidsp-shd volumio[724]: info: ControllerMpd::getState Sep 08 21:26:15 minidsp-shd volumio[724]: verbose: ControllerMpd::sendMpdCommand status Sep 08 21:26:15 minidsp-shd volumio[724]: info: sendMpdCommand status took 7 milliseconds Sep 08 21:26:15 minidsp-shd volumio[724]: info: sendMpdCommand status took 4 milliseconds Sep 08 21:26:15 minidsp-shd volumio[724]: info: sendMpdCommand status took 3 milliseconds Sep 08 21:26:15 minidsp-shd volumio[724]: verbose: ControllerMpd::parseState Sep 08 21:26:15 minidsp-shd volumio[724]: verbose: ControllerMpd::parseState Sep 08 21:26:15 minidsp-shd volumio[724]: verbose: ControllerMpd::parseState Sep 08 21:26:15 minidsp-shd volumio[724]: info: ControllerMpd::pushState Sep 08 21:26:15 minidsp-shd volumio[724]: info: CoreCommandRouter::servicePushState Sep 08 21:26:15 minidsp-shd volumio[724]: info: CoreStateMachine::pushState Sep 08 21:26:15 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 08 21:26:15 minidsp-shd volumio[724]: info: CoreCommandRouter::volumioPushState Sep 08 21:26:15 minidsp-shd volumio[724]: info: MRS: Pushing multiroomSync output update for this device Sep 08 21:26:15 minidsp-shd volumio[724]: info: MRS: Pushing multiroomSync output Sep 08 21:26:15 minidsp-shd volumio[724]: info: CorePlayQueue::getTrack 35 Sep 08 21:26:15 minidsp-shd volumio[724]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Sep 08 21:26:15 minidsp-shd volumio[724]: verbose: CURRENT POSITION 35 Sep 08 21:26:15 minidsp-shd volumio[724]: info: CoreStateMachine::syncState stateService stop Sep 08 21:26:15 minidsp-shd volumio[724]: info: CoreStateMachine::syncState currentStatus play Sep 08 21:26:15 minidsp-shd volumio[724]: info: CoreCommandRouter::volumioPushState Sep 08 21:26:15 minidsp-shd volumio[724]: info: MRS: Pushing multiroomSync output update for this device Sep 08 21:26:15 minidsp-shd volumio[724]: info: MRS: Pushing multiroomSync output Sep 08 21:26:15 minidsp-shd volumio[724]: info: CoreStateMachine::stPlaybackTimer Sep 08 21:26:15 minidsp-shd volumio[724]: info: ControllerMpd::pushState Sep 08 21:26:15 minidsp-shd volumio[724]: info: CoreCommandRouter::servicePushState Sep 08 21:26:15 minidsp-shd volumio[724]: info: CoreStateMachine::pushState Sep 08 21:26:15 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 08 21:26:15 minidsp-shd volumio[724]: info: CoreCommandRouter::volumioPushState Sep 08 21:26:15 minidsp-shd volumio[724]: info: MRS: Pushing multiroomSync output update for this device Sep 08 21:26:15 minidsp-shd volumio[724]: info: MRS: Pushing multiroomSync output Sep 08 21:26:15 minidsp-shd volumio[724]: info: CorePlayQueue::getTrack 0 Sep 08 21:26:15 minidsp-shd volumio[724]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Sep 08 21:26:15 minidsp-shd volumio[724]: verbose: CURRENT POSITION 0 Sep 08 21:26:15 minidsp-shd volumio[724]: info: CoreStateMachine::syncState stateService stop Sep 08 21:26:15 minidsp-shd volumio[724]: info: CoreStateMachine::syncState currentStatus stop Sep 08 21:26:15 minidsp-shd volumio[724]: info: CoreStateMachine::pushState Sep 08 21:26:15 minidsp-shd volumio[724]: info: CoreCommandRouter::volumioPushState Sep 08 21:26:15 minidsp-shd volumio[724]: info: MRS: Pushing multiroomSync output update for this device Sep 08 21:26:15 minidsp-shd volumio[724]: info: MRS: Pushing multiroomSync output Sep 08 21:26:15 minidsp-shd volumio[724]: info: No code Sep 08 21:26:15 minidsp-shd volumio[724]: info: CoreStateMachine::pushState Sep 08 21:26:15 minidsp-shd volumio[724]: info: CoreCommandRouter::volumioPushState Sep 08 21:26:15 minidsp-shd volumio[724]: info: MRS: Pushing multiroomSync output update for this device Sep 08 21:26:15 minidsp-shd volumio[724]: info: MRS: Pushing multiroomSync output Sep 08 21:26:15 minidsp-shd volumio[724]: info: ControllerMpd::pushState Sep 08 21:26:15 minidsp-shd volumio[724]: info: CoreCommandRouter::servicePushState Sep 08 21:26:15 minidsp-shd volumio[724]: info: CoreStateMachine::pushState Sep 08 21:26:15 minidsp-shd volumio[724]: info: CoreCommandRouter::volumioPushState Sep 08 21:26:15 minidsp-shd volumio[724]: info: MRS: Pushing multiroomSync output update for this device Sep 08 21:26:15 minidsp-shd volumio[724]: info: MRS: Pushing multiroomSync output Sep 08 21:26:15 minidsp-shd volumio[724]: info: CorePlayQueue::getTrack 0 Sep 08 21:26:15 minidsp-shd volumio[724]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Sep 08 21:26:15 minidsp-shd volumio[724]: verbose: CURRENT POSITION 0 Sep 08 21:26:15 minidsp-shd volumio[724]: info: CoreStateMachine::syncState stateService stop Sep 08 21:26:15 minidsp-shd volumio[724]: info: CoreStateMachine::syncState currentStatus stop Sep 08 21:26:15 minidsp-shd volumio[724]: info: CoreStateMachine::pushState Sep 08 21:26:15 minidsp-shd volumio[724]: info: CoreCommandRouter::volumioPushState Sep 08 21:26:15 minidsp-shd volumio[724]: info: MRS: Pushing multiroomSync output update for this device Sep 08 21:26:15 minidsp-shd volumio[724]: info: MRS: Pushing multiroomSync output Sep 08 21:26:15 minidsp-shd volumio[724]: info: No code Sep 08 21:26:15 minidsp-shd volumio[724]: info: CoreStateMachine::pushState Sep 08 21:26:15 minidsp-shd volumio[724]: info: CoreCommandRouter::volumioPushState Sep 08 21:26:15 minidsp-shd volumio[724]: info: MRS: Pushing multiroomSync output update for this device Sep 08 21:26:15 minidsp-shd volumio[724]: info: MRS: Pushing multiroomSync output Sep 08 21:26:15 minidsp-shd volumio[724]: info: ------------------------------ 70ms Sep 08 21:26:15 minidsp-shd volumio[724]: info: ------------------------------ 69ms Sep 08 21:26:15 minidsp-shd volumio[724]: info: ------------------------------ 68ms Sep 08 21:26:15 minidsp-shd volumio[724]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 Sep 08 21:26:15 minidsp-shd volumio[724]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 Sep 08 21:26:15 minidsp-shd volumio[724]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 Sep 08 21:26:15 minidsp-shd volumio[724]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 Sep 08 21:26:15 minidsp-shd volumio[724]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 Sep 08 21:26:15 minidsp-shd volumio[724]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 Sep 08 21:26:15 minidsp-shd volumio[724]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 Sep 08 21:26:15 minidsp-shd volumio[724]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 Sep 08 21:26:15 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 08 21:26:15 minidsp-shd volumio[724]: info: Received Get System Info Sep 08 21:26:15 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 08 21:26:15 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 08 21:26:15 minidsp-shd volumio[724]: info: Discovery: Getting this device information Sep 08 21:26:15 minidsp-shd volumio[724]: info: CoreCommandRouter::volumioGetState Sep 08 21:26:15 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 08 21:26:15 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 08 21:26:15 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1018. Sep 08 21:26:15 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 08 21:26:15 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 08 21:26:15 minidsp-shd go-librespot[21724]: Librespot-go daemon starting... Sep 08 21:26:15 minidsp-shd go-librespot[21724]: time="2024-09-08T21:26:15+01:00" level=info msg="generated new device id: 236322f5db027d7f6d9aebb7998016cd7c64c419" Sep 08 21:26:15 minidsp-shd go-librespot[21724]: time="2024-09-08T21:26:15+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 08 21:26:15 minidsp-shd go-librespot[21724]: time="2024-09-08T21:26:15+01:00" level=debug msg="obtained new client token: AAAaucxu3+0aZwux/eYh4cVsoBqyLXFJOBk7Kr60jk6pLV5WelgjidK2FOIwShr44KTGu7gzCMnV0W/OrZ/KC9TkTboGSQfu0JUf/k3WlW8tJVPso+xaB5MEbMiRC1vOb8rVUHukLGVODbF9GPxkYX75yXHmszB2baT74hlpOzQWhU5hiniHTgVw2DLC/HlR/QvgDsTIzmrVj5DMxqvw8oiznriuCPBvMk0AXRicryPNnQIvTyEnDFMCVEhtZCo=" Sep 08 21:26:16 minidsp-shd volumio[724]: Searching all installed plugins Sep 08 21:26:16 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 08 21:26:16 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: , search Sep 08 21:26:16 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: mpd , search Sep 08 21:26:16 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search Sep 08 21:26:16 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: last_100 , search Sep 08 21:26:16 minidsp-shd volumio[724]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 Sep 08 21:26:16 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: webradio , search Sep 08 21:26:16 minidsp-shd go-librespot[21724]: time="2024-09-08T21:26:16+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-guc3.spotify.com:4070 ap2-gew4.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 08 21:26:16 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: calmradio , search Sep 08 21:26:16 minidsp-shd volumio[724]: info: [1725827176079] ControllerCalmRadio::searchCategories Sep 08 21:26:16 minidsp-shd volumio[724]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 08 21:26:16 minidsp-shd volumio[724]: TypeError: Cannot read property 'cats' of undefined Sep 08 21:26:16 minidsp-shd volumio[724]: at ControllerCalmRadio.searchCategories (/data/plugins/music_service/calmradio/index.js:615:42) Sep 08 21:26:16 minidsp-shd volumio[724]: at ControllerCalmRadio.search (/data/plugins/music_service/calmradio/index.js:665:28) Sep 08 21:26:16 minidsp-shd volumio[724]: at CoreCommandRouter.executeOnPlugin (/volumio/app/index.js:1077:32) Sep 08 21:26:16 minidsp-shd volumio[724]: at CoreMusicLibrary.searchOnPlugin (/volumio/app/musiclibrary.js:668:44) Sep 08 21:26:16 minidsp-shd volumio[724]: at CoreMusicLibrary.search (/volumio/app/musiclibrary.js:455:27) Sep 08 21:26:16 minidsp-shd volumio[724]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:457:44) Sep 08 21:26:16 minidsp-shd volumio[724]: at Socket.emit (events.js:400:28) Sep 08 21:26:16 minidsp-shd volumio[724]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 Sep 08 21:26:16 minidsp-shd volumio[724]: at processTicksAndRejections (internal/process/task_queues.js:77:11) Sep 08 21:26:16 minidsp-shd volumio[724]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 08 21:26:16 minidsp-shd go-librespot[21724]: time="2024-09-08T21:26:16+01:00" level=debug msg="completed keyexchange" Sep 08 21:26:16 minidsp-shd go-librespot[21724]: time="2024-09-08T21:26:16+01:00" level=debug msg="completed challenge" Sep 08 21:26:16 minidsp-shd go-librespot[21724]: time="2024-09-08T21:26:16+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 08 21:26:16 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 08 21:26:16 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 08 21:26:16 minidsp-shd sudo[21741]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-09-08 21:25 Sep 08 21:26:16 minidsp-shd sudo[21741]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="17fcb754ddd6bd152b01008c46cc4ba1ca48bf35" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="281cefcd7a302aa7cfba569185cf7aae19b8c376" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="minidspshd" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 22 Mar 2024 03:00:28 PM CET" VOLUMIO_VERSION="3.608" VOLUMIO_HARDWARE="nanopineo2" VOLUMIO_DEVICENAME="NanoPi Neo2" VOLUMIO_VENDOR="miniDSP" VOLUMIO_MODEL="SHD" VOLUMIO_VENDOR_MODEL="miniDSP SHD" VOLUMIO_HASH="29ccfe8a9cff19911db4b736879ac117"