-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Sun 2024-10-27 08:27:05 CET. -- Oct 27 08:26:00 volumio-chambre go-librespot[8097]: time="2024-10-27T08:26:00+01:00" level=debug msg="completed challenge" Oct 27 08:26:00 volumio-chambre go-librespot[8097]: time="2024-10-27T08:26:00+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 27 08:26:00 volumio-chambre systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 27 08:26:00 volumio-chambre systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 27 08:26:01 volumio-chambre volumio[1125]: Searching plugin music_service/qobuz Oct 27 08:26:01 volumio-chambre volumio[1125]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Oct 27 08:26:01 volumio-chambre volumio[1125]: info: searchQOBUZUri took 2442 milliseconds Oct 27 08:26:01 volumio-chambre volumio[1125]: info: All search sources collected, pushing search results Oct 27 08:26:02 volumio-chambre volumio[1125]: info: Initializing connection to go-librespot Websocket Oct 27 08:26:02 volumio-chambre volumio[1125]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 08:26:03 volumio-chambre volumio[1125]: info: searchQOBUZUri took 2218 milliseconds Oct 27 08:26:03 volumio-chambre volumio[1125]: info: All search sources collected, pushing search results Oct 27 08:26:03 volumio-chambre systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 27 08:26:03 volumio-chambre systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 517. Oct 27 08:26:03 volumio-chambre systemd[1]: Stopped go-librespot Daemon. Oct 27 08:26:03 volumio-chambre systemd[1]: Started go-librespot Daemon. Oct 27 08:26:03 volumio-chambre go-librespot[8106]: Librespot-go daemon starting... Oct 27 08:26:03 volumio-chambre go-librespot[8106]: time="2024-10-27T08:26:03+01:00" level=info msg="generated new device id: 76c7caceb6c4cc5aee0f1f9dc15c7df249d3df31" Oct 27 08:26:03 volumio-chambre go-librespot[8106]: time="2024-10-27T08:26:03+01:00" level=debug msg="stored credentials found for lmouldaia" Oct 27 08:26:03 volumio-chambre go-librespot[8106]: time="2024-10-27T08:26:03+01:00" level=debug msg="obtained new client token: AABp6olSQlqWqRx+0/nPzdPLYW0IBQQBKjFYtryQhXxlbjqiNvgb2MpfF3WINfOko5YfeEukd0YfuHM8dOdJxLp62mwsYt/xa5tcrCmTHTM42aLhO//B5Ob0H5VqgMrAvgYAfY5kpuEaL2vmssZ/o/2Yc5Dx+ooTOE6PBf4+fa3xdeFieHt70nHincQulEEQMQhBKDDmgsNSKhRAwyuHN5EwFpV0nym1afXE6+ruw+Yi89eczV6ywDyFUVUFlQ==" Oct 27 08:26:03 volumio-chambre go-librespot[8106]: time="2024-10-27T08:26:03+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Oct 27 08:26:03 volumio-chambre go-librespot[8106]: time="2024-10-27T08:26:03+01:00" level=debug msg="completed keyexchange" Oct 27 08:26:04 volumio-chambre go-librespot[8106]: time="2024-10-27T08:26:04+01:00" level=debug msg="completed challenge" Oct 27 08:26:04 volumio-chambre go-librespot[8106]: time="2024-10-27T08:26: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" Oct 27 08:26:04 volumio-chambre systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 27 08:26:04 volumio-chambre systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 27 08:26:05 volumio-chambre volumio[1125]: info: Initializing connection to go-librespot Websocket Oct 27 08:26:05 volumio-chambre volumio[1125]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 08:26:07 volumio-chambre systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 27 08:26:07 volumio-chambre systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 518. Oct 27 08:26:07 volumio-chambre systemd[1]: Stopped go-librespot Daemon. Oct 27 08:26:07 volumio-chambre systemd[1]: Started go-librespot Daemon. Oct 27 08:26:07 volumio-chambre go-librespot[8114]: Librespot-go daemon starting... Oct 27 08:26:07 volumio-chambre go-librespot[8114]: time="2024-10-27T08:26:07+01:00" level=info msg="generated new device id: 3e51946ae790a55dd03298d9ea803e3f6a092644" Oct 27 08:26:07 volumio-chambre go-librespot[8114]: time="2024-10-27T08:26:07+01:00" level=debug msg="stored credentials found for lmouldaia" Oct 27 08:26:07 volumio-chambre go-librespot[8114]: time="2024-10-27T08:26:07+01:00" level=debug msg="obtained new client token: AABJVsWh4E7WsnXoPsYcbNoy1Le3BdcX3aZiW8DVqvr4WjskUiXPa0wkJtvLkKBoVE3bYNVK4CHYmNGJJa7YUbMQagnS9MxP60YGh0Ebr962jHSQkcZT6DRf75/M4OxajB8Sqf8vER+e1R/uUwEgMa0t3DbXCrI8ogTBTa6AQhzJvLwYoqnkFNmw5d8HVjyglFfFl4RP6fjkOF+15XfQ4BS0K3RsA6z+L4MTP3i2Vupqav1TYTX3wH7NVjX80Q==" Oct 27 08:26:07 volumio-chambre go-librespot[8114]: time="2024-10-27T08:26:07+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 27 08:26:07 volumio-chambre go-librespot[8114]: time="2024-10-27T08:26:07+01:00" level=debug msg="completed keyexchange" Oct 27 08:26:08 volumio-chambre go-librespot[8114]: time="2024-10-27T08:26:08+01:00" level=debug msg="completed challenge" Oct 27 08:26:08 volumio-chambre go-librespot[8114]: time="2024-10-27T08:26: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" Oct 27 08:26:08 volumio-chambre systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 27 08:26:08 volumio-chambre systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 27 08:26:08 volumio-chambre volumio[1125]: info: Initializing connection to go-librespot Websocket Oct 27 08:26:08 volumio-chambre volumio[1125]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 08:26:09 volumio-chambre volumio[1125]: Searching plugin music_service/qobuz Oct 27 08:26:09 volumio-chambre volumio[1125]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Oct 27 08:26:11 volumio-chambre volumio[1125]: info: Initializing connection to go-librespot Websocket Oct 27 08:26:11 volumio-chambre volumio[1125]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 08:26:11 volumio-chambre systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 27 08:26:11 volumio-chambre systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 519. Oct 27 08:26:11 volumio-chambre systemd[1]: Stopped go-librespot Daemon. Oct 27 08:26:11 volumio-chambre systemd[1]: Started go-librespot Daemon. Oct 27 08:26:11 volumio-chambre go-librespot[8122]: Librespot-go daemon starting... Oct 27 08:26:11 volumio-chambre go-librespot[8122]: time="2024-10-27T08:26:11+01:00" level=info msg="generated new device id: bdb12028d4fc4dc924f863d7c80803a3cc46d78d" Oct 27 08:26:11 volumio-chambre go-librespot[8122]: time="2024-10-27T08:26:11+01:00" level=debug msg="stored credentials found for lmouldaia" Oct 27 08:26:11 volumio-chambre go-librespot[8122]: time="2024-10-27T08:26:11+01:00" level=debug msg="obtained new client token: AAAQZyo1FJevy1FE9BsDhdV/XkgR+dN+vThBsIEHR0UGgk7gighSLWTVEBztwEzcste7ebpXdzCDFvj1L1GxVGQGTM3nqC+VpmbrvIgeB2T3WVUeVe4QqHsx2t+cjxKagPptsBH3CJyE4o2CIMY8NebW+hyFU58ePDw2e3HdgfD/GGmnOyXzKxaRXLeGRjgoBlz3PZPlctPpzpNtlI0O3SKAuY1MJJrsi0aVR1meTPMClY0PfLv65Clt7EfX6Q==" Oct 27 08:26:11 volumio-chambre go-librespot[8122]: time="2024-10-27T08:26:11+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 27 08:26:11 volumio-chambre volumio[1125]: Searching plugin music_service/qobuz Oct 27 08:26:11 volumio-chambre volumio[1125]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Oct 27 08:26:11 volumio-chambre volumio[1125]: info: searchQOBUZUri took 1859 milliseconds Oct 27 08:26:11 volumio-chambre volumio[1125]: info: All search sources collected, pushing search results Oct 27 08:26:11 volumio-chambre go-librespot[8122]: time="2024-10-27T08:26:11+01:00" level=debug msg="completed keyexchange" Oct 27 08:26:12 volumio-chambre go-librespot[8122]: time="2024-10-27T08:26:12+01:00" level=debug msg="completed challenge" Oct 27 08:26:12 volumio-chambre go-librespot[8122]: time="2024-10-27T08: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" Oct 27 08:26:12 volumio-chambre systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 27 08:26:12 volumio-chambre systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 27 08:26:13 volumio-chambre volumio[1125]: Searching plugin music_service/qobuz Oct 27 08:26:13 volumio-chambre volumio[1125]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Oct 27 08:26:13 volumio-chambre volumio[1125]: Searching plugin music_service/qobuz Oct 27 08:26:13 volumio-chambre volumio[1125]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Oct 27 08:26:14 volumio-chambre volumio[1125]: info: searchQOBUZUri took 2247 milliseconds Oct 27 08:26:14 volumio-chambre volumio[1125]: info: All search sources collected, pushing search results Oct 27 08:26:14 volumio-chambre volumio[1125]: info: Initializing connection to go-librespot Websocket Oct 27 08:26:14 volumio-chambre volumio[1125]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 08:26:14 volumio-chambre volumio[1125]: info: searchQOBUZUri took 980 milliseconds Oct 27 08:26:14 volumio-chambre volumio[1125]: info: All search sources collected, pushing search results Oct 27 08:26:15 volumio-chambre volumio[1125]: info: searchQOBUZUri took 2030 milliseconds Oct 27 08:26:15 volumio-chambre volumio[1125]: info: All search sources collected, pushing search results Oct 27 08:26:15 volumio-chambre systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 27 08:26:15 volumio-chambre systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 520. Oct 27 08:26:15 volumio-chambre systemd[1]: Stopped go-librespot Daemon. Oct 27 08:26:15 volumio-chambre systemd[1]: Started go-librespot Daemon. Oct 27 08:26:15 volumio-chambre go-librespot[8130]: Librespot-go daemon starting... Oct 27 08:26:15 volumio-chambre go-librespot[8130]: time="2024-10-27T08:26:15+01:00" level=info msg="generated new device id: bfb40fa6f743a21025706767bdc8ee783a63d834" Oct 27 08:26:15 volumio-chambre go-librespot[8130]: time="2024-10-27T08:26:15+01:00" level=debug msg="stored credentials found for lmouldaia" Oct 27 08:26:15 volumio-chambre go-librespot[8130]: time="2024-10-27T08:26:15+01:00" level=debug msg="obtained new client token: AADiWHKbEAFM8We9mLNwFS/Lx4oJUxXHjAYB7rRBlNSpU7yKED8WUlbw6JRkjHaKoWgA6noxXng1V2Jr2LhMvfzaYXbUA1BgFlr/FF5FkRUXdyhd4pPW1WbT/TRksSbwdYDBxmjhPv/wRG20zvGZI2QVOTI0obJlHncydmDnc47Fy+ytL7gG7SCS1Hie5iPVG7Kf0UNLlCeNdxO4e/REqq20nh+JZZKLYNj+JFK4oxwH0q0Fk9UVbiLixNlYHw==" Oct 27 08:26:15 volumio-chambre go-librespot[8130]: time="2024-10-27T08:26:15+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Oct 27 08:26:15 volumio-chambre go-librespot[8130]: time="2024-10-27T08:26:15+01:00" level=debug msg="completed keyexchange" Oct 27 08:26:16 volumio-chambre go-librespot[8130]: time="2024-10-27T08:26:16+01:00" level=debug msg="completed challenge" Oct 27 08:26:16 volumio-chambre go-librespot[8130]: time="2024-10-27T08: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" Oct 27 08:26:16 volumio-chambre systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 27 08:26:16 volumio-chambre systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 27 08:26:17 volumio-chambre volumio[1125]: info: Initializing connection to go-librespot Websocket Oct 27 08:26:17 volumio-chambre volumio[1125]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 08:26:19 volumio-chambre systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 27 08:26:19 volumio-chambre systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 521. Oct 27 08:26:19 volumio-chambre systemd[1]: Stopped go-librespot Daemon. Oct 27 08:26:19 volumio-chambre systemd[1]: Started go-librespot Daemon. Oct 27 08:26:19 volumio-chambre go-librespot[8138]: Librespot-go daemon starting... Oct 27 08:26:19 volumio-chambre go-librespot[8138]: time="2024-10-27T08:26:19+01:00" level=info msg="generated new device id: b67f1dccdc9cf9f7c598f14e4f97beea8d7da289" Oct 27 08:26:19 volumio-chambre go-librespot[8138]: time="2024-10-27T08:26:19+01:00" level=debug msg="stored credentials found for lmouldaia" Oct 27 08:26:19 volumio-chambre go-librespot[8138]: time="2024-10-27T08:26:19+01:00" level=debug msg="obtained new client token: AAC5rq6bsnj+8WcY5kYLybBC3Remo1gwG9X8xJitfRPhpHU6BB+P6RKQJ4VsbP/Sbsv9WrwhEXTs/J9cScqyK3EOPv5IqAlQNHhaZla9m0oBP41fI1MT9GieHT+B2cthZqvcXXrzRck+cGEyFktreluQHWADmnaOilVSKSnbpqPjjMjoNDPjCLkyDyADPsAGGE1vKcw1shJHW/NJOEvmeEh6I3h/vgoMntsaC7DIXPawN13KjYKgSeGdxvEwWA==" Oct 27 08:26:19 volumio-chambre go-librespot[8138]: time="2024-10-27T08:26:19+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 27 08:26:19 volumio-chambre go-librespot[8138]: time="2024-10-27T08:26:19+01:00" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed dialing accesspoint: dial tcp 104.199.65.9:4070: connect: connection refused" Oct 27 08:26:19 volumio-chambre systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 27 08:26:19 volumio-chambre systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 27 08:26:20 volumio-chambre volumio[1125]: info: Initializing connection to go-librespot Websocket Oct 27 08:26:20 volumio-chambre volumio[1125]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 08:26:21 volumio-chambre volumiologrotate[670]: ls: cannot access '/var/log/samba/log.wb-VOLUMIO': No such file or directory Oct 27 08:26:21 volumio-chambre volumiologrotate[670]: ls: cannot access 'CHAMBRE': No such file or directory Oct 27 08:26:23 volumio-chambre systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 27 08:26:23 volumio-chambre systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 522. Oct 27 08:26:23 volumio-chambre systemd[1]: Stopped go-librespot Daemon. Oct 27 08:26:23 volumio-chambre systemd[1]: Started go-librespot Daemon. Oct 27 08:26:23 volumio-chambre go-librespot[8188]: Librespot-go daemon starting... Oct 27 08:26:23 volumio-chambre go-librespot[8188]: time="2024-10-27T08:26:23+01:00" level=info msg="generated new device id: 066cce0878d62be24bda102b8ae71bfa341dd996" Oct 27 08:26:23 volumio-chambre go-librespot[8188]: time="2024-10-27T08:26:23+01:00" level=debug msg="stored credentials found for lmouldaia" Oct 27 08:26:23 volumio-chambre go-librespot[8188]: time="2024-10-27T08:26:23+01:00" level=debug msg="obtained new client token: AAAsjMYQ024vu+QZHvu7cwS9adniN6BZTH0xNhIacgt5dHS8d0RH0a8k2g0/az0oAoq85Gu1KAPO7rtvUTWuYEEea8q7+BY6+sqSrtKk5jjCeT3XnPTJKjAy7+jGoFidtRhOrGCPN84xyV4xnfUPOcj7KhmtTgO/JDm6+SBxufG+6qlbkm+j060wLGf+DadwemDppN0jvmRmSDElYcZVXHIiekPf3jjy7JZNlqM8xzzhqGL+7SYQcgQ5vl8=" Oct 27 08:26:23 volumio-chambre go-librespot[8188]: time="2024-10-27T08:26:23+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Oct 27 08:26:23 volumio-chambre go-librespot[8188]: time="2024-10-27T08:26:23+01:00" level=debug msg="completed keyexchange" Oct 27 08:26:23 volumio-chambre volumio[1125]: info: Initializing connection to go-librespot Websocket Oct 27 08:26:23 volumio-chambre go-librespot[8188]: time="2024-10-27T08:26:23+01:00" level=debug msg="new websocket client" Oct 27 08:26:23 volumio-chambre volumio[1125]: info: Connection to go-librespot Websocket established Oct 27 08:26:23 volumio-chambre go-librespot[8188]: time="2024-10-27T08:26:23+01:00" level=debug msg="completed challenge" Oct 27 08:26:23 volumio-chambre go-librespot[8188]: time="2024-10-27T08:26: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" Oct 27 08:26:23 volumio-chambre systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 27 08:26:23 volumio-chambre systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 27 08:26:23 volumio-chambre volumio[1125]: info: Connection to go-librespot Websocket closed Oct 27 08:26:26 volumio-chambre volumio[1125]: info: Getting Spotify volume Oct 27 08:26:26 volumio-chambre volumio[1125]: (node:1125) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 08:26:26 volumio-chambre volumio[1125]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Oct 27 08:26:26 volumio-chambre volumio[1125]: (node:1125) 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) Oct 27 08:26:26 volumio-chambre volumio[1125]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Oct 27 08:26:26 volumio-chambre volumio[1125]: info: CoreCommandRouter::volumioGetState Oct 27 08:26:26 volumio-chambre volumio[1125]: info: CorePlayQueue::getTrack 2 Oct 27 08:26:26 volumio-chambre volumio[1125]: SPOTIFY: RECEIVED VOLUMIO VOLUME 88 Oct 27 08:26:26 volumio-chambre volumio[1125]: info: Initializing connection to go-librespot Websocket Oct 27 08:26:26 volumio-chambre volumio[1125]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 08:26:27 volumio-chambre systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 27 08:26:27 volumio-chambre systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 523. Oct 27 08:26:27 volumio-chambre systemd[1]: Stopped go-librespot Daemon. Oct 27 08:26:27 volumio-chambre systemd[1]: Started go-librespot Daemon. Oct 27 08:26:27 volumio-chambre go-librespot[8196]: Librespot-go daemon starting... Oct 27 08:26:27 volumio-chambre go-librespot[8196]: time="2024-10-27T08:26:27+01:00" level=info msg="generated new device id: 374144f9018882aecd07b75e6e4163a5de33e9f1" Oct 27 08:26:27 volumio-chambre go-librespot[8196]: time="2024-10-27T08:26:27+01:00" level=debug msg="stored credentials found for lmouldaia" Oct 27 08:26:27 volumio-chambre go-librespot[8196]: time="2024-10-27T08:26:27+01:00" level=debug msg="obtained new client token: AAAAS7FnPvuMlcYA1unhRXZAH3IHvAkGUBna3Wajgxm/SpjjmiD976vr/cVkhv5Ryg+nM+vNRBQfZXPjEFkIasAE9wVqpDITNvY1e6OMlfsbidk17cRuv/W7aJEUzWH1jM+CRXaDXX/Yxc8nTEWCSw90Z7fOIvC8unExYZeN2DN+1JK/Um8i3/RhjDBzpvXrqO/zqZF95gvmBLSnbAZnWGxi9ws1EkOdV158n4/3nfJfYNxLdHdjJsxV00I=" Oct 27 08:26:27 volumio-chambre go-librespot[8196]: time="2024-10-27T08:26:27+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 27 08:26:27 volumio-chambre go-librespot[8196]: time="2024-10-27T08:26:27+01:00" level=debug msg="completed keyexchange" Oct 27 08:26:27 volumio-chambre volumio[1125]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Oct 27 08:26:27 volumio-chambre go-librespot[8196]: time="2024-10-27T08:26:27+01:00" level=debug msg="completed challenge" Oct 27 08:26:27 volumio-chambre go-librespot[8196]: time="2024-10-27T08:26:27+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 27 08:26:27 volumio-chambre systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 27 08:26:27 volumio-chambre systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 27 08:26:27 volumio-chambre volumio[1125]: info: handleBrowseUri took 495 milliseconds Oct 27 08:26:27 volumio-chambre volumio[1125]: info: Preload queue cleared Oct 27 08:26:27 volumio-chambre volumio[1125]: info: Preloading song: qobuz://song/231002293 Oct 27 08:26:28 volumio-chambre volumio[1125]: info: Exploding uri qobuz://song/231002293 in service qobuz Oct 27 08:26:28 volumio-chambre volumio[1125]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 27 08:26:28 volumio-chambre volumio[1125]: info: Executing endpoint getSimilarAlbums Oct 27 08:26:28 volumio-chambre volumio[1125]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Oct 27 08:26:28 volumio-chambre volumio[1125]: info: Executing endpoint metavolumio Oct 27 08:26:28 volumio-chambre volumio[1125]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 27 08:26:28 volumio-chambre volumio[1125]: info: Executing endpoint metavolumio Oct 27 08:26:28 volumio-chambre volumio[1125]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 27 08:26:28 volumio-chambre volumio[1125]: info: explodeUri took 592 milliseconds Oct 27 08:26:29 volumio-chambre volumio[1125]: info: Initializing connection to go-librespot Websocket Oct 27 08:26:29 volumio-chambre volumio[1125]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 08:26:31 volumio-chambre systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 27 08:26:31 volumio-chambre systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 524. Oct 27 08:26:31 volumio-chambre systemd[1]: Stopped go-librespot Daemon. Oct 27 08:26:31 volumio-chambre systemd[1]: Started go-librespot Daemon. Oct 27 08:26:31 volumio-chambre go-librespot[8204]: Librespot-go daemon starting... Oct 27 08:26:31 volumio-chambre go-librespot[8204]: time="2024-10-27T08:26:31+01:00" level=info msg="generated new device id: ae5579e4d14fe4ba3cc4d6ed4180b8e20369fdda" Oct 27 08:26:31 volumio-chambre go-librespot[8204]: time="2024-10-27T08:26:31+01:00" level=debug msg="stored credentials found for lmouldaia" Oct 27 08:26:31 volumio-chambre go-librespot[8204]: time="2024-10-27T08:26:31+01:00" level=debug msg="obtained new client token: AAAJkhSGp8/b3pzKHkc4IWU7xEgfX+OO/ACdZED2aXZ2uZZ/v2GGsnB2jokW0iBDMcP5TiEJeUh0Fkct+4qeN5kf83xZ+lAzJCeqbTzHpA7UYemLi2GIrgxgcD2KmilAq6yRydVEuSxqcJqyKWJ3lD95R5/Mc7EUbuZ8JTIo1A7qKpBQG64/IeUOtCm7Rkl8cF8OwQN+3QF19+HcgyZGYppxeN+LWUV8y4bvoS+Iwj4vIHACs6S1iEGXE1U=" Oct 27 08:26:31 volumio-chambre go-librespot[8204]: time="2024-10-27T08:26:31+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 27 08:26:31 volumio-chambre go-librespot[8204]: time="2024-10-27T08:26:31+01:00" level=debug msg="completed keyexchange" Oct 27 08:26:31 volumio-chambre go-librespot[8204]: time="2024-10-27T08:26:31+01:00" level=debug msg="completed challenge" Oct 27 08:26:31 volumio-chambre go-librespot[8204]: time="2024-10-27T08:26:31+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 27 08:26:31 volumio-chambre systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 27 08:26:31 volumio-chambre systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 27 08:26:32 volumio-chambre volumio[1125]: info: Initializing connection to go-librespot Websocket Oct 27 08:26:32 volumio-chambre volumio[1125]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 08:26:35 volumio-chambre systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 27 08:26:35 volumio-chambre systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 525. Oct 27 08:26:35 volumio-chambre systemd[1]: Stopped go-librespot Daemon. Oct 27 08:26:35 volumio-chambre systemd[1]: Started go-librespot Daemon. Oct 27 08:26:35 volumio-chambre go-librespot[8213]: Librespot-go daemon starting... Oct 27 08:26:35 volumio-chambre go-librespot[8213]: time="2024-10-27T08:26:35+01:00" level=info msg="generated new device id: eef1960dccb667b9fe4ee724d6c3a0137644afcc" Oct 27 08:26:35 volumio-chambre go-librespot[8213]: time="2024-10-27T08:26:35+01:00" level=debug msg="stored credentials found for lmouldaia" Oct 27 08:26:35 volumio-chambre volumio[1125]: error: Failed request for metavolumio API Oct 27 08:26:35 volumio-chambre go-librespot[8213]: time="2024-10-27T08:26:35+01:00" level=debug msg="obtained new client token: AACCO6r4TC8q8aPQhVbetGmD3a9JGTvjIOq/fuy0cjEYRiIUTqZG0nPT6FMYBpy9L2z6AZqsIqQocWESXDCMWjVpw6WLNhvVAG71c0H4freJp5ILBYXfdsPENnkrNzV2gulVV3WYZ8VRW2KJ+aNdfC5fV75lN75J/ACddUKxBfGxywRP2W6A8eLheRtPHvW60l3YsY7Sd12L7/U9wKPJFKwoRu7HnsVcBGw5Puq1zJMM/3ieFvM8nrctjBs=" Oct 27 08:26:35 volumio-chambre go-librespot[8213]: time="2024-10-27T08:26:35+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Oct 27 08:26:35 volumio-chambre go-librespot[8213]: time="2024-10-27T08:26:35+01:00" level=debug msg="completed keyexchange" Oct 27 08:26:35 volumio-chambre go-librespot[8213]: time="2024-10-27T08:26:35+01:00" level=debug msg="completed challenge" Oct 27 08:26:35 volumio-chambre go-librespot[8213]: time="2024-10-27T08:26:35+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 27 08:26:35 volumio-chambre systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 27 08:26:35 volumio-chambre systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 27 08:26:35 volumio-chambre volumio[1125]: info: Initializing connection to go-librespot Websocket Oct 27 08:26:35 volumio-chambre volumio[1125]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 08:26:38 volumio-chambre volumio[1125]: info: Initializing connection to go-librespot Websocket Oct 27 08:26:38 volumio-chambre volumio[1125]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 08:26:39 volumio-chambre systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 27 08:26:39 volumio-chambre systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 526. Oct 27 08:26:39 volumio-chambre systemd[1]: Stopped go-librespot Daemon. Oct 27 08:26:39 volumio-chambre systemd[1]: Started go-librespot Daemon. Oct 27 08:26:39 volumio-chambre go-librespot[8222]: Librespot-go daemon starting... Oct 27 08:26:39 volumio-chambre go-librespot[8222]: time="2024-10-27T08:26:39+01:00" level=info msg="generated new device id: ecf930c12bfed12f66ebf23a8acb5c18205a2374" Oct 27 08:26:39 volumio-chambre go-librespot[8222]: time="2024-10-27T08:26:39+01:00" level=debug msg="stored credentials found for lmouldaia" Oct 27 08:26:39 volumio-chambre go-librespot[8222]: time="2024-10-27T08:26:39+01:00" level=debug msg="obtained new client token: AAD9iTMEfwplE0Mv+GUCwxqiRpq94GQ7IWfjl9EAivT+frU6Wz4a1YTBLEi0KcmTHoF0xBw7SFl6Gzg47GT4YrarQvD6CmnsY2E6KHCynJH+enTF7am5phWshNCRBFPrKpPPWVqGsm9f23z6BDSgaH2X30ex1Uhf4f6OQJ0H2dmfrOIkvs2Wv1UevxKCIA4v8lo/WPF02KXClXNv6WU3nGQc0QhfI70vXOUyzlcWqJUoBCkNigfWCyvqApU=" Oct 27 08:26:39 volumio-chambre go-librespot[8222]: time="2024-10-27T08:26:39+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 27 08:26:39 volumio-chambre go-librespot[8222]: time="2024-10-27T08:26:39+01:00" level=debug msg="completed keyexchange" Oct 27 08:26:39 volumio-chambre go-librespot[8222]: time="2024-10-27T08:26:39+01:00" level=debug msg="completed challenge" Oct 27 08:26:39 volumio-chambre go-librespot[8222]: time="2024-10-27T08:26:39+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 27 08:26:39 volumio-chambre systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 27 08:26:39 volumio-chambre systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 27 08:26:41 volumio-chambre volumio[1125]: info: Initializing connection to go-librespot Websocket Oct 27 08:26:41 volumio-chambre volumio[1125]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 08:26:43 volumio-chambre systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 27 08:26:43 volumio-chambre systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 527. Oct 27 08:26:43 volumio-chambre systemd[1]: Stopped go-librespot Daemon. Oct 27 08:26:43 volumio-chambre volumio[1125]: info: CorePlayQueue::getTrack 2 Oct 27 08:26:43 volumio-chambre volumio[1125]: info: CorePlayQueue::getTrack 3 Oct 27 08:26:43 volumio-chambre volumio[1125]: info: Prefetching next song Oct 27 08:26:43 volumio-chambre volumio[1125]: info: [1730014003036] ControllerQobuz::prefetch Oct 27 08:26:43 volumio-chambre volumio[1125]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/76736699" Oct 27 08:26:43 volumio-chambre volumio[1125]: STREAMING PROXY: Handling url /?data=qobuz://song/76736699 Oct 27 08:26:43 volumio-chambre volumio[1125]: info: Executing endpoint getStreamUrlqobuz Oct 27 08:26:43 volumio-chambre volumio[1125]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 27 08:26:43 volumio-chambre systemd[1]: Started go-librespot Daemon. Oct 27 08:26:43 volumio-chambre go-librespot[8231]: Librespot-go daemon starting... Oct 27 08:26:43 volumio-chambre go-librespot[8231]: time="2024-10-27T08:26:43+01:00" level=info msg="generated new device id: 4b01a5350edf9774f5877233961c809c13ed8cc4" Oct 27 08:26:43 volumio-chambre go-librespot[8231]: time="2024-10-27T08:26:43+01:00" level=debug msg="stored credentials found for lmouldaia" Oct 27 08:26:43 volumio-chambre go-librespot[8231]: time="2024-10-27T08:26:43+01:00" level=debug msg="obtained new client token: AACU8GmG1E5dqMK2touAEUJ9kbEzbrZbWYV5GEPDb+9SkRga45w9J4hXFiZZhko4795XCVTrZ6i9C7MP8APX5xIFDe9lWkRNJ5FJw19lbSW9X2Hb77mcuavNu9UAjJucCH9LiQ2fG3sRzu8dVifv6J/usma4f64E6p9WXx7wYfLON7ZJPAczPDJ/La0L9YlBLOTJkiuiGqqEIsl0f9lu87Y15URez5cKLN1Xg2d9SkLoIoVTb+nm2sT1RDA=" Oct 27 08:26:43 volumio-chambre go-librespot[8231]: time="2024-10-27T08:26:43+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 27 08:26:43 volumio-chambre go-librespot[8231]: time="2024-10-27T08:26:43+01:00" level=debug msg="completed keyexchange" Oct 27 08:26:43 volumio-chambre volumio[1125]: info: getStreamUrl took 563 milliseconds Oct 27 08:26:43 volumio-chambre volumio[1125]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=2888464&eid=76736699&fmt=6&profile=raw&app_id=539451548&cid=2092215&etsp=1730017603&hmac=mbdE7jJ3gMZqZpdqwlgpZjaQf5w Oct 27 08:26:43 volumio-chambre go-librespot[8231]: time="2024-10-27T08:26:43+01:00" level=debug msg="completed challenge" Oct 27 08:26:43 volumio-chambre volumio[1125]: STREAMING PROXY: Response: 200, length: 24944316 Oct 27 08:26:43 volumio-chambre volumio[1125]: STREAMING PROXY: Client dropped request, destroying Oct 27 08:26:43 volumio-chambre volumio[1125]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/76736699" Oct 27 08:26:43 volumio-chambre volumio[1125]: info: Oct 27 08:26:43 volumio-chambre volumio[1125]: ---------------------------- MPD announces system playlist update Oct 27 08:26:43 volumio-chambre volumio[1125]: info: Ignoring MPD Status Update Oct 27 08:26:43 volumio-chambre volumio[1125]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/76736699" took 1 milliseconds Oct 27 08:26:43 volumio-chambre volumio[1125]: STREAMING PROXY: Handling url /?data=qobuz://song/76736699 Oct 27 08:26:43 volumio-chambre volumio[1125]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 27 08:26:43 volumio-chambre volumio[1125]: verbose: ControllerMpd::sendMpdCommand consume 1 Oct 27 08:26:43 volumio-chambre volumio[1125]: info: ------------------------------ 2ms Oct 27 08:26:43 volumio-chambre volumio[1125]: info: sendMpdCommand consume 1 took 1 milliseconds Oct 27 08:26:43 volumio-chambre volumio[1125]: info: Executing endpoint getStreamUrlqobuz Oct 27 08:26:43 volumio-chambre volumio[1125]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 27 08:26:43 volumio-chambre go-librespot[8231]: time="2024-10-27T08:26:43+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 27 08:26:43 volumio-chambre systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 27 08:26:43 volumio-chambre systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 27 08:26:44 volumio-chambre volumio[1125]: info: getStreamUrl took 590 milliseconds Oct 27 08:26:44 volumio-chambre volumio[1125]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=2888464&eid=76736699&fmt=6&profile=raw&app_id=539451548&cid=2092215&etsp=1730017604&hmac=H8Cy9RWn5QVaAeOuoQIeEVMZ3Us Oct 27 08:26:44 volumio-chambre volumio[1125]: STREAMING PROXY: Response: 200, length: 24944316 Oct 27 08:26:44 volumio-chambre volumio[1125]: STREAMING PROXY: Client dropped request, destroying Oct 27 08:26:44 volumio-chambre volumio[1125]: info: Initializing connection to go-librespot Websocket Oct 27 08:26:44 volumio-chambre volumio[1125]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 08:26:47 volumio-chambre systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 27 08:26:47 volumio-chambre systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 528. Oct 27 08:26:47 volumio-chambre systemd[1]: Stopped go-librespot Daemon. Oct 27 08:26:47 volumio-chambre systemd[1]: Started go-librespot Daemon. Oct 27 08:26:47 volumio-chambre go-librespot[8241]: Librespot-go daemon starting... Oct 27 08:26:47 volumio-chambre go-librespot[8241]: time="2024-10-27T08:26:47+01:00" level=info msg="generated new device id: 28253a6bb5da0b1aed8d160f39c3da3dd3e4222c" Oct 27 08:26:47 volumio-chambre go-librespot[8241]: time="2024-10-27T08:26:47+01:00" level=debug msg="stored credentials found for lmouldaia" Oct 27 08:26:47 volumio-chambre go-librespot[8241]: time="2024-10-27T08:26:47+01:00" level=debug msg="obtained new client token: AADYdyJs8hjvpdsxO3BaHQSSh2hPWxK0BJ3tmguL3N5d4fkzXgRtl9YjP4pFdC/dIVsYsXnmGiW2ZVnqwWhfTy/C6zM7VDbOptLSZmTZt+GLdNjHTD9kFRKcVZfjJ+a+OTt5QFO50Kv+DlGp+R5HJ5odG22NCi7F1wInwkCrUxBg5vACsEAcAP1iAvZtntrXsTrRCKR9d2EjS/Evkn5XPTFAssHQHSqoh2ETmvCufrPxMscgGExnDHPpMiU=" Oct 27 08:26:47 volumio-chambre go-librespot[8241]: time="2024-10-27T08:26:47+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Oct 27 08:26:47 volumio-chambre go-librespot[8241]: time="2024-10-27T08:26:47+01:00" level=debug msg="completed keyexchange" Oct 27 08:26:47 volumio-chambre volumio[1125]: info: CoreStateMachine::startPlaybackTimer Oct 27 08:26:47 volumio-chambre volumio[1125]: info: CorePlayQueue::getTrack 3 Oct 27 08:26:47 volumio-chambre volumio[1125]: info: Oct 27 08:26:47 volumio-chambre volumio[1125]: ---------------------------- MPD announces system playlist update Oct 27 08:26:47 volumio-chambre volumio[1125]: info: Ignoring MPD Status Update Oct 27 08:26:47 volumio-chambre volumio[1125]: info: Oct 27 08:26:47 volumio-chambre volumio[1125]: ---------------------------- MPD announces state update: player Oct 27 08:26:47 volumio-chambre volumio[1125]: info: ControllerMpd::getState Oct 27 08:26:47 volumio-chambre volumio[1125]: verbose: ControllerMpd::sendMpdCommand status Oct 27 08:26:47 volumio-chambre volumio[1125]: info: ------------------------------ 2ms Oct 27 08:26:47 volumio-chambre volumio[1125]: info: sendMpdCommand status took 1 milliseconds Oct 27 08:26:47 volumio-chambre volumio[1125]: verbose: ControllerMpd::parseState Oct 27 08:26:47 volumio-chambre volumio[1125]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 27 08:26:47 volumio-chambre volumio[1125]: info: sendMpdCommand playlistinfo took 0 milliseconds Oct 27 08:26:47 volumio-chambre volumio[1125]: verbose: ControllerMpd::parseTrackInfo Oct 27 08:26:47 volumio-chambre volumio[1125]: info: ControllerMpd::pushState Oct 27 08:26:47 volumio-chambre volumio[1125]: info: CoreCommandRouter::servicePushState Oct 27 08:26:47 volumio-chambre volumio[1125]: info: CorePlayQueue::getTrack 3 Oct 27 08:26:47 volumio-chambre volumio[1125]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":261,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"496 Kbps","isStreaming":false,"title":"76736699","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/76736699","trackType":"qobuz"} Oct 27 08:26:47 volumio-chambre volumio[1125]: verbose: CURRENT POSITION 3 Oct 27 08:26:47 volumio-chambre volumio[1125]: info: CoreStateMachine::syncState stateService play Oct 27 08:26:47 volumio-chambre volumio[1125]: info: CoreStateMachine::syncState currentStatus play Oct 27 08:26:47 volumio-chambre volumio[1125]: info: Received an update from plugin. extracting info from payload Oct 27 08:26:47 volumio-chambre volumio[1125]: info: CoreStateMachine::pushState Oct 27 08:26:47 volumio-chambre volumio[1125]: info: CorePlayQueue::getTrack 3 Oct 27 08:26:47 volumio-chambre volumio[1125]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 27 08:26:47 volumio-chambre volumio[1125]: info: CoreCommandRouter::volumioPushState Oct 27 08:26:47 volumio-chambre volumio[1125]: info: MRS: Pushing multiroomSync output update for this device Oct 27 08:26:47 volumio-chambre volumio[1125]: info: MRS: Pushing multiroomSync output Oct 27 08:26:47 volumio-chambre volumio[1125]: info: CoreStateMachine::pushState Oct 27 08:26:47 volumio-chambre volumio[1125]: info: CorePlayQueue::getTrack 3 Oct 27 08:26:47 volumio-chambre volumio[1125]: info: CoreCommandRouter::volumioPushState Oct 27 08:26:47 volumio-chambre volumio[1125]: info: MRS: Pushing multiroomSync output update for this device Oct 27 08:26:47 volumio-chambre volumio[1125]: info: MRS: Pushing multiroomSync output Oct 27 08:26:47 volumio-chambre volumio[1125]: info: ------------------------------ 34ms Oct 27 08:26:47 volumio-chambre volumio[1125]: SPOTIFY: RECEIVED VOLUMIO VOLUME 88 Oct 27 08:26:47 volumio-chambre volumio[1125]: SPOTIFY: RECEIVED VOLUMIO VOLUME 88 Oct 27 08:26:47 volumio-chambre go-librespot[8241]: time="2024-10-27T08:26:47+01:00" level=debug msg="completed challenge" Oct 27 08:26:47 volumio-chambre go-librespot[8241]: time="2024-10-27T08:26:47+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 27 08:26:47 volumio-chambre systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 27 08:26:47 volumio-chambre systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 27 08:26:47 volumio-chambre volumio[1125]: info: Initializing connection to go-librespot Websocket Oct 27 08:26:47 volumio-chambre volumio[1125]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 08:26:48 volumio-chambre volumio[1125]: info: CoreStateMachine::pushState Oct 27 08:26:48 volumio-chambre volumio[1125]: info: CorePlayQueue::getTrack 3 Oct 27 08:26:48 volumio-chambre volumio[1125]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 27 08:26:48 volumio-chambre volumio[1125]: info: CoreCommandRouter::volumioPushState Oct 27 08:26:48 volumio-chambre volumio[1125]: info: MRS: Pushing multiroomSync output update for this device Oct 27 08:26:48 volumio-chambre volumio[1125]: info: MRS: Pushing multiroomSync output Oct 27 08:26:48 volumio-chambre volumio[1125]: SPOTIFY: RECEIVED VOLUMIO VOLUME 88 Oct 27 08:26:50 volumio-chambre volumio[1125]: info: Initializing connection to go-librespot Websocket Oct 27 08:26:50 volumio-chambre volumio[1125]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 08:26:51 volumio-chambre systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 27 08:26:51 volumio-chambre systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 529. Oct 27 08:26:51 volumio-chambre systemd[1]: Stopped go-librespot Daemon. Oct 27 08:26:51 volumio-chambre systemd[1]: Started go-librespot Daemon. Oct 27 08:26:51 volumio-chambre go-librespot[8249]: Librespot-go daemon starting... Oct 27 08:26:51 volumio-chambre go-librespot[8249]: time="2024-10-27T08:26:51+01:00" level=info msg="generated new device id: 4d4ca39eb1d399e2992f9314379a85b4267e4012" Oct 27 08:26:51 volumio-chambre go-librespot[8249]: time="2024-10-27T08:26:51+01:00" level=debug msg="stored credentials found for lmouldaia" Oct 27 08:26:51 volumio-chambre go-librespot[8249]: time="2024-10-27T08:26:51+01:00" level=debug msg="obtained new client token: AABvMRSajSfhLRj80UXz0tTYRGJ0Ur/DiTW34cD9zlBv63rx49hVQnhPqueNxStftPEq9AOD+GA6zSpMyB1VkBnA7BT1sYNMNu/MggsDgBxxpmkJSgWmq3u4AyE8Oc74a35ZXmCUGtvfFutVtK7o9eGJiyRg5WyrLJN1/enpFptKXuSk1kUnBt0Zl8Pe53bUyOHDfDiJ3oAUvhYyhaX1g5fXpwYYRdRVNhQNqocw91voeAfb3QQH07z+bxI=" Oct 27 08:26:51 volumio-chambre go-librespot[8249]: time="2024-10-27T08:26:51+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 27 08:26:51 volumio-chambre go-librespot[8249]: time="2024-10-27T08:26:51+01:00" level=debug msg="completed keyexchange" Oct 27 08:26:51 volumio-chambre go-librespot[8249]: time="2024-10-27T08:26:51+01:00" level=debug msg="completed challenge" Oct 27 08:26:51 volumio-chambre go-librespot[8249]: time="2024-10-27T08:26:51+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 27 08:26:51 volumio-chambre systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 27 08:26:51 volumio-chambre systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 27 08:26:53 volumio-chambre volumio[1125]: info: Initializing connection to go-librespot Websocket Oct 27 08:26:53 volumio-chambre volumio[1125]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 08:26:55 volumio-chambre systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 27 08:26:55 volumio-chambre systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 530. Oct 27 08:26:55 volumio-chambre systemd[1]: Stopped go-librespot Daemon. Oct 27 08:26:55 volumio-chambre systemd[1]: Started go-librespot Daemon. Oct 27 08:26:55 volumio-chambre go-librespot[8258]: Librespot-go daemon starting... Oct 27 08:26:55 volumio-chambre go-librespot[8258]: time="2024-10-27T08:26:55+01:00" level=info msg="generated new device id: 95daeeda83d53e35c30dd329ca00e34ce0f8a918" Oct 27 08:26:55 volumio-chambre go-librespot[8258]: time="2024-10-27T08:26:55+01:00" level=debug msg="stored credentials found for lmouldaia" Oct 27 08:26:55 volumio-chambre go-librespot[8258]: time="2024-10-27T08:26:55+01:00" level=debug msg="obtained new client token: AAC7Ry2Ndv8/HnZvBnweWGy5z1TiQpK04bV5AVkb/eBumFD2zPGd3xk90lz7HIx1Dx4OO/lokIVotMzGNxqKyfkyi2bNubTBpHqIJB1zAoayO7uX7zmTWN1oDJh8MDb0DTEDC8bM+jSavzOcZxRHtwesnMVOAKBmUCnURqSpFiPJa2UFKbYPNAxWoDrSo6GwGLC2mM6aiwGWq2ykBFzkTx+owT57yPnPzofQmw1wCy3vFPgj7KBuqxfbt1k=" Oct 27 08:26:55 volumio-chambre go-librespot[8258]: time="2024-10-27T08:26:55+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Oct 27 08:26:55 volumio-chambre go-librespot[8258]: time="2024-10-27T08:26:55+01:00" level=debug msg="completed keyexchange" Oct 27 08:26:55 volumio-chambre go-librespot[8258]: time="2024-10-27T08:26:55+01:00" level=debug msg="completed challenge" Oct 27 08:26:56 volumio-chambre go-librespot[8258]: time="2024-10-27T08:26:56+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 27 08:26:56 volumio-chambre systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 27 08:26:56 volumio-chambre systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 27 08:26:56 volumio-chambre volumio[1125]: info: Initializing connection to go-librespot Websocket Oct 27 08:26:56 volumio-chambre volumio[1125]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 08:26:59 volumio-chambre volumio[1125]: info: Initializing connection to go-librespot Websocket Oct 27 08:26:59 volumio-chambre volumio[1125]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 08:27:00 volumio-chambre systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 27 08:27:00 volumio-chambre systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 531. Oct 27 08:27:00 volumio-chambre systemd[1]: Stopped go-librespot Daemon. Oct 27 08:27:00 volumio-chambre systemd[1]: Started go-librespot Daemon. Oct 27 08:27:00 volumio-chambre go-librespot[8266]: Librespot-go daemon starting... Oct 27 08:27:00 volumio-chambre go-librespot[8266]: time="2024-10-27T08:27:00+01:00" level=info msg="generated new device id: 3f8898d26778965139cd6a8b51ef739a67dc2f33" Oct 27 08:27:00 volumio-chambre go-librespot[8266]: time="2024-10-27T08:27:00+01:00" level=debug msg="stored credentials found for lmouldaia" Oct 27 08:27:00 volumio-chambre go-librespot[8266]: time="2024-10-27T08:27:00+01:00" level=debug msg="obtained new client token: AACSiC9UyUS7OeZ0sh86EPgbWG9VTYXXWOlS8cQQyiXHGjKNwRAw5OSTyPKnZH0xdA++SiiBMEWvAPtU1AyAjwLgdwhmTiwNedI8qkW8XzZgTlIEWN8QqJdXRBB15TKQ32edPnJzKvJsaDbl+jNGRoZzUdQTWmAZHR9OO7h2Qx/xACPQlsT4l84ruPfEEjobAyn+57zcb/QHZjNobdZg4yOCrEejEhSIKbXPKsUg4wUyNgMEj/CfMWBZpCA=" Oct 27 08:27:00 volumio-chambre go-librespot[8266]: time="2024-10-27T08:27:00+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 27 08:27:00 volumio-chambre go-librespot[8266]: time="2024-10-27T08:27:00+01:00" level=debug msg="completed keyexchange" Oct 27 08:27:00 volumio-chambre go-librespot[8266]: time="2024-10-27T08:27:00+01:00" level=debug msg="completed challenge" Oct 27 08:27:00 volumio-chambre go-librespot[8266]: time="2024-10-27T08:27:00+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 27 08:27:00 volumio-chambre systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 27 08:27:00 volumio-chambre systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 27 08:27:02 volumio-chambre volumio[1125]: info: Initializing connection to go-librespot Websocket Oct 27 08:27:02 volumio-chambre volumio[1125]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 08:27:04 volumio-chambre systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 27 08:27:04 volumio-chambre systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 532. Oct 27 08:27:04 volumio-chambre systemd[1]: Stopped go-librespot Daemon. Oct 27 08:27:04 volumio-chambre systemd[1]: Started go-librespot Daemon. Oct 27 08:27:04 volumio-chambre go-librespot[8275]: Librespot-go daemon starting... Oct 27 08:27:04 volumio-chambre go-librespot[8275]: time="2024-10-27T08:27:04+01:00" level=info msg="generated new device id: a532c38f2022c61b8e0b99998fb6500262d122ee" Oct 27 08:27:04 volumio-chambre go-librespot[8275]: time="2024-10-27T08:27:04+01:00" level=debug msg="stored credentials found for lmouldaia" Oct 27 08:27:04 volumio-chambre go-librespot[8275]: time="2024-10-27T08:27:04+01:00" level=debug msg="obtained new client token: AABLYBzMjMgS5/6/6vRM+c0Adfjjsd0FLYibwY01cF/wZZH4JBO0CgghWoBmpt6rfqoijlsWiFoCj4rWb7e6kIAGwkB7GdFXaFbHN6M5BwNYzZjnhvyXv9illE9MGpJh0pV0Dwh0s8aXEq/svVStWV5TYU3KMnKgEC+ERLpaKgy1eghucX7D5bXayLecxHpPrstsju2dM5W8U5H6PNVOEwJvQ+P1vw2ZX361vuEhy4PiNFSXnekmY/zZASw=" Oct 27 08:27:04 volumio-chambre go-librespot[8275]: time="2024-10-27T08:27:04+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Oct 27 08:27:04 volumio-chambre go-librespot[8275]: time="2024-10-27T08:27:04+01:00" level=debug msg="completed keyexchange" Oct 27 08:27:04 volumio-chambre go-librespot[8275]: time="2024-10-27T08:27:04+01:00" level=debug msg="completed challenge" Oct 27 08:27:04 volumio-chambre volumio[1125]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 27 08:27:04 volumio-chambre volumio[1125]: Error: connect ETIMEDOUT 199.232.170.79:443 Oct 27 08:27:04 volumio-chambre volumio[1125]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) { Oct 27 08:27:04 volumio-chambre volumio[1125]: errno: -110, Oct 27 08:27:04 volumio-chambre volumio[1125]: code: 'ETIMEDOUT', Oct 27 08:27:04 volumio-chambre volumio[1125]: syscall: 'connect', Oct 27 08:27:04 volumio-chambre volumio[1125]: address: '199.232.170.79', Oct 27 08:27:04 volumio-chambre volumio[1125]: port: 443 Oct 27 08:27:04 volumio-chambre volumio[1125]: } Oct 27 08:27:04 volumio-chambre volumio[1125]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 27 08:27:04 volumio-chambre go-librespot[8275]: time="2024-10-27T08:27: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" Oct 27 08:27:04 volumio-chambre systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 27 08:27:04 volumio-chambre systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 27 08:27:05 volumio-chambre sudo[8292]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-27 08:26 Oct 27 08:27:05 volumio-chambre sudo[8292]: 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="bba9e3185e150dd0995f9a49355b34fc6218d5a2" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8aa57e3ae5b742ea1069404608336a9884ccfb4e" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 17 Sep 2024 05:01:09 PM CEST" VOLUMIO_VERSION="3.757" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="e0a6dc7e914e3fb93cbf2123f2f73eac"