-- Logs begin at Tue 2024-10-29 10:48:06 CET, end at Tue 2024-10-29 11:06:44 CET. -- Oct 29 11:05:00 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 29 11:05:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 189. Oct 29 11:05:00 volumio systemd[1]: Stopped go-librespot Daemon. Oct 29 11:05:00 volumio systemd[1]: Started go-librespot Daemon. Oct 29 11:05:00 volumio go-librespot[6802]: Librespot-go daemon starting... Oct 29 11:05:00 volumio go-librespot[6802]: time="2024-10-29T11:05:00+01:00" level=info msg="generated new device id: e13007887fb9432da784bdaf82690287a3df97a2" Oct 29 11:05:00 volumio go-librespot[6802]: time="2024-10-29T11:05:00+01:00" level=debug msg="stored credentials found for 31n3mfaqxn3pbyb6v7nkastad4j4" Oct 29 11:05:01 volumio go-librespot[6802]: time="2024-10-29T11:05:01+01:00" level=debug msg="obtained new client token: AAAqelQmeFpSgxj4pB/AscA/c0BxZR+cDBdhACPU4x1kkfCr2NSXUHWFGzDcxh2J6MGEwpCVrxk8pm8W41u+eWrlgYbev4CE2/LymZw9QZjUSoD5igT+Z4T/KDZNAUp+jhextqRPgmk4ZoWnS+OAdai0VtcW52GwPreyIa8jgU4/VFwWxdU8RCPPuTncfzYZds/jEZ6qNo7mFopWaQ2V8l6A8JHiSK/RnKHcZFYsbdP0PBqPPWae+/T4o8yGo97oQQ==" Oct 29 11:05:01 volumio go-librespot[6802]: time="2024-10-29T11:05:01+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 29 11:05:01 volumio volumio[1034]: info: Initializing connection to go-librespot Websocket Oct 29 11:05:01 volumio go-librespot[6802]: time="2024-10-29T11:05:01+01:00" level=debug msg="new websocket client" Oct 29 11:05:01 volumio volumio[1034]: info: Connection to go-librespot Websocket established Oct 29 11:05:01 volumio go-librespot[6802]: time="2024-10-29T11:05:01+01:00" level=debug msg="completed keyexchange" Oct 29 11:05:02 volumio volumio[1034]: info: Selecting previously unselected package fonts-ipafont-gothic. Oct 29 11:05:02 volumio volumio[1034]: info: Preparing to unpack .../01-fonts-ipafont-gothic_00303-18_all.deb ... Oct 29 11:05:02 volumio go-librespot[6802]: time="2024-10-29T11:05:02+01:00" level=debug msg="completed challenge" Oct 29 11:05:02 volumio go-librespot[6802]: time="2024-10-29T11:05:02+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 29 11:05:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 29 11:05:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 29 11:05:02 volumio volumio[1034]: info: Connection to go-librespot Websocket closed Oct 29 11:05:02 volumio volumio[1034]: info: Unpacking fonts-ipafont-gothic (00303-18) ... Oct 29 11:05:04 volumio volumio[1034]: info: Getting Spotify volume Oct 29 11:05:04 volumio volumio[1034]: (node:1034) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 11:05:04 volumio volumio[1034]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Oct 29 11:05:04 volumio volumio[1034]: (node:1034) 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: 89) Oct 29 11:05:04 volumio volumio[1034]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Oct 29 11:05:04 volumio volumio[1034]: info: CoreCommandRouter::volumioGetState Oct 29 11:05:04 volumio volumio[1034]: info: CorePlayQueue::getTrack 0 Oct 29 11:05:04 volumio volumio[1034]: SPOTIFY: RECEIVED VOLUMIO VOLUME 98 Oct 29 11:05:05 volumio volumio[1034]: info: Initializing connection to go-librespot Websocket Oct 29 11:05:05 volumio volumio[1034]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 11:05:05 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 29 11:05:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 190. Oct 29 11:05:05 volumio systemd[1]: Stopped go-librespot Daemon. Oct 29 11:05:05 volumio systemd[1]: Started go-librespot Daemon. Oct 29 11:05:05 volumio go-librespot[6824]: Librespot-go daemon starting... Oct 29 11:05:05 volumio go-librespot[6824]: time="2024-10-29T11:05:05+01:00" level=info msg="generated new device id: c8ebdcde8e92361830d9a9c8c105bba6521649a0" Oct 29 11:05:05 volumio go-librespot[6824]: time="2024-10-29T11:05:05+01:00" level=debug msg="stored credentials found for 31n3mfaqxn3pbyb6v7nkastad4j4" Oct 29 11:05:06 volumio go-librespot[6824]: time="2024-10-29T11:05:06+01:00" level=debug msg="obtained new client token: AAC/jRKlMVInl26Mw1PAwP8vY/h89WKRRFBzkFrIwJLA8fmWK7cNa7LJs2JJ61X2KnE+Wjkn5PvuHAfKsG9FMBxSY25X79gpOf27tWcdZ4WRtSdL8mYsDzeLZPnO+6a3BWTpjic7vrVmKpWUGBSr1M1U1yl+IY6R44sWo7+r95vofvAQYIIlFACnNOgA0dIEMLJ/Ky5HOaVSLl+Rek2u1znXu6HyzJQqeGjffi0em4w+oiR1vH2RVEG9NVYhZDo=" Oct 29 11:05:06 volumio go-librespot[6824]: time="2024-10-29T11:05:06+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 29 11:05:06 volumio go-librespot[6824]: time="2024-10-29T11:05:06+01:00" level=debug msg="completed keyexchange" Oct 29 11:05:06 volumio volumio[1034]: info: Selecting previously unselected package fonts-ipafont-mincho. Oct 29 11:05:06 volumio volumio[1034]: info: Preparing to unpack .../02-fonts-ipafont-mincho_00303-18_all.deb ... Oct 29 11:05:07 volumio go-librespot[6824]: time="2024-10-29T11:05:07+01:00" level=debug msg="completed challenge" Oct 29 11:05:07 volumio volumio[1034]: info: Unpacking fonts-ipafont-mincho (00303-18) ... Oct 29 11:05:07 volumio go-librespot[6824]: time="2024-10-29T11:05: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" Oct 29 11:05:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 29 11:05:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 29 11:05:08 volumio volumio[1034]: info: Initializing connection to go-librespot Websocket Oct 29 11:05:08 volumio volumio[1034]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 11:05:10 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 29 11:05:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 191. Oct 29 11:05:10 volumio systemd[1]: Stopped go-librespot Daemon. Oct 29 11:05:10 volumio systemd[1]: Started go-librespot Daemon. Oct 29 11:05:10 volumio go-librespot[6846]: Librespot-go daemon starting... Oct 29 11:05:10 volumio go-librespot[6846]: time="2024-10-29T11:05:10+01:00" level=info msg="generated new device id: 501b7ccd14b6a04ca96d08a050c7b880c8fdff2b" Oct 29 11:05:10 volumio go-librespot[6846]: time="2024-10-29T11:05:10+01:00" level=debug msg="stored credentials found for 31n3mfaqxn3pbyb6v7nkastad4j4" Oct 29 11:05:10 volumio go-librespot[6846]: time="2024-10-29T11:05:10+01:00" level=debug msg="obtained new client token: AAAtkqL1ePruICxuwM7rYyStWAbsLgBp6AAaS7ojv6BpdFfqSJq3ribAckicv4fDiIemQyliVoyocbsE0vMoOiPkqZ5m28gTmzFe6QKM4tv8kPidLUI3cst7ldKZOtgRwdjtP37aS0orysTpWfYbJZd7IEVMi4vHYh7fgrTgKxcYOwOlEKVZjlTsG9xVqHpa9mTUK3YN6a+aqfz4a+bCSj8/SIF4WFAdbYyd7V3s0/9pQ4AZGcQp797C5f7NcoDCNw==" Oct 29 11:05:11 volumio go-librespot[6846]: time="2024-10-29T11:05: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 29 11:05:11 volumio go-librespot[6846]: time="2024-10-29T11:05:11+01:00" level=debug msg="completed keyexchange" Oct 29 11:05:11 volumio volumio[1034]: info: Initializing connection to go-librespot Websocket Oct 29 11:05:11 volumio go-librespot[6846]: time="2024-10-29T11:05:11+01:00" level=debug msg="new websocket client" Oct 29 11:05:11 volumio volumio[1034]: info: Connection to go-librespot Websocket established Oct 29 11:05:11 volumio go-librespot[6846]: time="2024-10-29T11:05:11+01:00" level=debug msg="completed challenge" Oct 29 11:05:11 volumio go-librespot[6846]: time="2024-10-29T11:05:11+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 29 11:05:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 29 11:05:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 29 11:05:11 volumio volumio[1034]: info: Connection to go-librespot Websocket closed Oct 29 11:05:13 volumio volumio[1034]: info: Selecting previously unselected package fonts-ipafont. Oct 29 11:05:13 volumio volumio[1034]: info: Preparing to unpack .../03-fonts-ipafont_00303-18_all.deb ... Oct 29 11:05:14 volumio volumio[1034]: info: Unpacking fonts-ipafont (00303-18) ... Oct 29 11:05:14 volumio volumio[1034]: info: Getting Spotify volume Oct 29 11:05:14 volumio volumio[1034]: (node:1034) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 11:05:14 volumio volumio[1034]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Oct 29 11:05:14 volumio volumio[1034]: (node:1034) 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: 90) Oct 29 11:05:14 volumio volumio[1034]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Oct 29 11:05:14 volumio volumio[1034]: info: CoreCommandRouter::volumioGetState Oct 29 11:05:14 volumio volumio[1034]: info: CorePlayQueue::getTrack 0 Oct 29 11:05:14 volumio volumio[1034]: SPOTIFY: RECEIVED VOLUMIO VOLUME 98 Oct 29 11:05:14 volumio volumio[1034]: info: Initializing connection to go-librespot Websocket Oct 29 11:05:14 volumio volumio[1034]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 11:05:14 volumio volumio[1034]: info: Selecting previously unselected package fonts-unfonts-core. Oct 29 11:05:14 volumio volumio[1034]: info: Preparing to unpack .../04-fonts-unfonts-core_1%3a1.0.2-080608-16_all.deb ... Oct 29 11:05:15 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 29 11:05:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 192. Oct 29 11:05:15 volumio systemd[1]: Stopped go-librespot Daemon. Oct 29 11:05:15 volumio systemd[1]: Started go-librespot Daemon. Oct 29 11:05:15 volumio go-librespot[6878]: Librespot-go daemon starting... Oct 29 11:05:15 volumio go-librespot[6878]: time="2024-10-29T11:05:15+01:00" level=info msg="generated new device id: 3d8bd0143987a635fc9903f3b5c626668ed877ae" Oct 29 11:05:15 volumio go-librespot[6878]: time="2024-10-29T11:05:15+01:00" level=debug msg="stored credentials found for 31n3mfaqxn3pbyb6v7nkastad4j4" Oct 29 11:05:15 volumio volumio[1034]: info: Unpacking fonts-unfonts-core (1:1.0.2-080608-16) ... Oct 29 11:05:15 volumio go-librespot[6878]: time="2024-10-29T11:05:15+01:00" level=debug msg="obtained new client token: AABILrI102GAoCPHQ8UfK9Hx3AKOcl2L5yJqGAVM5DKAR4BEoJaUhcS6C4Ybx+XnI19Od9UfT9MP6IE1uZYlctvpo/bhRgval4OW0HbXvE974VuyoBwidWP7rmq0UBt+QR+vqtXXGTRySbNnM7Xa3XHZvaTI8WztJjuokrzffe1sKMQs/KRYHRct9kR9cWTf0pFCIx+nuWW1V9SdLWJE7uCJMb5JmvIvAeOWpdUQhWSBWsAgWpx3tXwyjTK4nXOz7A==" Oct 29 11:05:15 volumio go-librespot[6878]: time="2024-10-29T11:05: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 29 11:05:16 volumio go-librespot[6878]: time="2024-10-29T11:05:16+01:00" level=debug msg="completed keyexchange" Oct 29 11:05:16 volumio go-librespot[6878]: time="2024-10-29T11:05:16+01:00" level=debug msg="completed challenge" Oct 29 11:05:16 volumio go-librespot[6878]: time="2024-10-29T11:05: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 29 11:05:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 29 11:05:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 29 11:05:17 volumio volumio[1034]: info: Initializing connection to go-librespot Websocket Oct 29 11:05:17 volumio volumio[1034]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 11:05:19 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 29 11:05:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 193. Oct 29 11:05:19 volumio systemd[1]: Stopped go-librespot Daemon. Oct 29 11:05:19 volumio systemd[1]: Started go-librespot Daemon. Oct 29 11:05:19 volumio go-librespot[6898]: Librespot-go daemon starting... Oct 29 11:05:19 volumio go-librespot[6898]: time="2024-10-29T11:05:19+01:00" level=info msg="generated new device id: db8b7df1cf644c5b0d5e11de8d07f1c6ba560343" Oct 29 11:05:19 volumio go-librespot[6898]: time="2024-10-29T11:05:19+01:00" level=debug msg="stored credentials found for 31n3mfaqxn3pbyb6v7nkastad4j4" Oct 29 11:05:20 volumio go-librespot[6898]: time="2024-10-29T11:05:20+01:00" level=debug msg="obtained new client token: AADsfo3MO/49AQJsusBcy5rDZ4Veod+JX3U8h8jM+1g71tPdjTeYEMokx2g+4Dt2TDZua+bQelHaJCx+asHAn98Sn9bYXdR/qW6WYvAtN/DnQuE4cXGXngOcAYS29C2/Ey2xLZmYQm9KUq6hA4BwAExJ4bHdOYOgvgK9qiMtF9Oaj3xkBlvyyMhh+uWTtZYkrqmvnVKi6WTMmwJ+IfJlkuRjPCq9mJBt06EfISKxJuDH7zPkZ6v2DvHykbUpWvFJkQ==" Oct 29 11:05:20 volumio volumio[1034]: info: Initializing connection to go-librespot Websocket Oct 29 11:05:20 volumio go-librespot[6898]: time="2024-10-29T11:05:20+01:00" level=debug msg="new websocket client" Oct 29 11:05:20 volumio volumio[1034]: info: Connection to go-librespot Websocket established Oct 29 11:05:20 volumio go-librespot[6898]: time="2024-10-29T11:05:20+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 29 11:05:21 volumio go-librespot[6898]: time="2024-10-29T11:05:21+01:00" level=debug msg="completed keyexchange" Oct 29 11:05:21 volumio go-librespot[6898]: time="2024-10-29T11:05:21+01:00" level=debug msg="completed challenge" Oct 29 11:05:21 volumio go-librespot[6898]: time="2024-10-29T11:05:21+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 29 11:05:21 volumio volumio[1034]: info: Connection to go-librespot Websocket closed Oct 29 11:05:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 29 11:05:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 29 11:05:23 volumio volumio[1034]: info: Getting Spotify volume Oct 29 11:05:23 volumio volumio[1034]: (node:1034) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 11:05:23 volumio volumio[1034]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Oct 29 11:05:23 volumio volumio[1034]: (node:1034) 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: 91) Oct 29 11:05:23 volumio volumio[1034]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Oct 29 11:05:23 volumio volumio[1034]: info: CoreCommandRouter::volumioGetState Oct 29 11:05:23 volumio volumio[1034]: info: CorePlayQueue::getTrack 0 Oct 29 11:05:23 volumio volumio[1034]: SPOTIFY: RECEIVED VOLUMIO VOLUME 98 Oct 29 11:05:24 volumio volumio[1034]: info: Initializing connection to go-librespot Websocket Oct 29 11:05:24 volumio volumio[1034]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 11:05:24 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 29 11:05:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 194. Oct 29 11:05:24 volumio systemd[1]: Stopped go-librespot Daemon. Oct 29 11:05:24 volumio systemd[1]: Started go-librespot Daemon. Oct 29 11:05:24 volumio go-librespot[6907]: Librespot-go daemon starting... Oct 29 11:05:24 volumio go-librespot[6907]: time="2024-10-29T11:05:24+01:00" level=info msg="generated new device id: 07c6d16bbcb33a6dfb4db2b6382e63ff898eedca" Oct 29 11:05:24 volumio go-librespot[6907]: time="2024-10-29T11:05:24+01:00" level=debug msg="stored credentials found for 31n3mfaqxn3pbyb6v7nkastad4j4" Oct 29 11:05:25 volumio go-librespot[6907]: time="2024-10-29T11:05:25+01:00" level=debug msg="obtained new client token: AACnor1XD8ZtHpL7KtnggM+WwOd7geW7NKEz9xY8GRx7SjGN6lb1b2bAvQ4C/z9dCFKLcWBmtHscmTUf/xdjwIXvz3hyHV2LcS3v3/kcQNCh4LIiQoFN5yyMDzUdNjaqgX2JJQLJbrlQoDla3MGJkIbrdJk71LVqJrMEP+vOeB1nxaUYR07fRqWd/SW/nzDSCAbULQ7E2hV26tprKVnLFjr8tj4pORKYukmV2Cf1P2T2uBJxPSdmm12/wcKGcgWZvQ==" Oct 29 11:05:25 volumio go-librespot[6907]: time="2024-10-29T11:05:25+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 29 11:05:25 volumio go-librespot[6907]: time="2024-10-29T11:05:25+01:00" level=debug msg="completed keyexchange" Oct 29 11:05:26 volumio go-librespot[6907]: time="2024-10-29T11:05:26+01:00" level=debug msg="completed challenge" Oct 29 11:05:26 volumio go-librespot[6907]: time="2024-10-29T11:05:26+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 29 11:05:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 29 11:05:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 29 11:05:27 volumio volumio[1034]: info: Initializing connection to go-librespot Websocket Oct 29 11:05:27 volumio volumio[1034]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 11:05:29 volumio volumio[1034]: info: Selecting previously unselected package fonts-vlgothic. Oct 29 11:05:29 volumio volumio[1034]: info: Preparing to unpack .../05-fonts-vlgothic_20141206-5_all.deb ... Oct 29 11:05:29 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 29 11:05:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 195. Oct 29 11:05:29 volumio systemd[1]: Stopped go-librespot Daemon. Oct 29 11:05:29 volumio systemd[1]: Started go-librespot Daemon. Oct 29 11:05:29 volumio go-librespot[6921]: Librespot-go daemon starting... Oct 29 11:05:29 volumio volumio[1034]: info: Unpacking fonts-vlgothic (20141206-5) ... Oct 29 11:05:29 volumio go-librespot[6921]: time="2024-10-29T11:05:29+01:00" level=info msg="generated new device id: 7127f5c55e81eb9e2d67019a57ef9dd2cadcf3ba" Oct 29 11:05:29 volumio go-librespot[6921]: time="2024-10-29T11:05:29+01:00" level=debug msg="stored credentials found for 31n3mfaqxn3pbyb6v7nkastad4j4" Oct 29 11:05:30 volumio go-librespot[6921]: time="2024-10-29T11:05:30+01:00" level=debug msg="obtained new client token: AABldRd/CvZ64NmSe2xQCpJ0TJ1t5yFm80B10QTxXZiJqx/LnFuZX1jueNcKmrUrZguyArbUA+4+ffgh9jLedsd0BgyNlE103c9T7PG4uggB+rTqqjl/0ZeKLxcIa7IXBux0jTgl1tQXr6rAvcGHYk4BM8hTIMRff37SmS4PSFKDfhyWQX1IUDw5Zv9LO/w6ZPXCla9PI5vYzhthJPKRIsXdX/tq348m7iZBl5SC5r6Y0cisxAaHaHGAtMiYa5o=" Oct 29 11:05:30 volumio go-librespot[6921]: time="2024-10-29T11:05:30+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 29 11:05:30 volumio go-librespot[6921]: time="2024-10-29T11:05:30+01:00" level=debug msg="completed keyexchange" Oct 29 11:05:30 volumio volumio[1034]: info: Initializing connection to go-librespot Websocket Oct 29 11:05:30 volumio go-librespot[6921]: time="2024-10-29T11:05:30+01:00" level=debug msg="new websocket client" Oct 29 11:05:30 volumio volumio[1034]: info: Connection to go-librespot Websocket established Oct 29 11:05:31 volumio go-librespot[6921]: time="2024-10-29T11:05:31+01:00" level=debug msg="completed challenge" Oct 29 11:05:31 volumio go-librespot[6921]: time="2024-10-29T11:05: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 29 11:05:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 29 11:05:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 29 11:05:31 volumio volumio[1034]: info: Connection to go-librespot Websocket closed Oct 29 11:05:32 volumio volumio[1034]: info: Selecting previously unselected package fonts-arphic-ukai. Oct 29 11:05:32 volumio volumio[1034]: info: Preparing to unpack .../06-fonts-arphic-ukai_0.2.20080216.2-4_all.deb ... Oct 29 11:05:32 volumio volumio[1034]: info: Unpacking fonts-arphic-ukai (0.2.20080216.2-4) ... Oct 29 11:05:33 volumio volumio[1034]: info: Getting Spotify volume Oct 29 11:05:33 volumio volumio[1034]: (node:1034) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 11:05:33 volumio volumio[1034]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Oct 29 11:05:33 volumio volumio[1034]: (node:1034) 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: 92) Oct 29 11:05:33 volumio volumio[1034]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Oct 29 11:05:33 volumio volumio[1034]: info: CoreCommandRouter::volumioGetState Oct 29 11:05:33 volumio volumio[1034]: info: CorePlayQueue::getTrack 0 Oct 29 11:05:33 volumio volumio[1034]: SPOTIFY: RECEIVED VOLUMIO VOLUME 98 Oct 29 11:05:34 volumio volumio[1034]: info: Initializing connection to go-librespot Websocket Oct 29 11:05:34 volumio volumio[1034]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 11:05:34 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 29 11:05:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 196. Oct 29 11:05:34 volumio systemd[1]: Stopped go-librespot Daemon. Oct 29 11:05:34 volumio systemd[1]: Started go-librespot Daemon. Oct 29 11:05:34 volumio go-librespot[6951]: Librespot-go daemon starting... Oct 29 11:05:34 volumio go-librespot[6951]: time="2024-10-29T11:05:34+01:00" level=info msg="generated new device id: 0f8a8686246db37eca8efdda46b16bf8718e3cf1" Oct 29 11:05:34 volumio go-librespot[6951]: time="2024-10-29T11:05:34+01:00" level=debug msg="stored credentials found for 31n3mfaqxn3pbyb6v7nkastad4j4" Oct 29 11:05:34 volumio go-librespot[6951]: time="2024-10-29T11:05:34+01:00" level=debug msg="obtained new client token: AABQu1p8L8R1W7KTjv9FtKLqn4Ka5qxuXyeunHYfvN86IWjX+q8yAX4xq4Oaqh3XPDM+PHRWzRZZGzmOis79Q9FXrsl37VzRt6VtpIL2Zn9uwsHBuqcEWV2KlWt/aHHHi3z5iZp2tG2g7CAOD7BO2SezDxGciAUM8aDaoVQQdH/C7B8+xbe4MPA2EOClzoxxBfxhaaVb4tFTIRWvtJF/zMtSfCcQhz2//5ZIPsjP8k1numiPeqNOdUmBoPVZ2VhfxA==" Oct 29 11:05:35 volumio go-librespot[6951]: time="2024-10-29T11:05: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-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 29 11:05:35 volumio go-librespot[6951]: time="2024-10-29T11:05:35+01:00" level=debug msg="completed keyexchange" Oct 29 11:05:35 volumio go-librespot[6951]: time="2024-10-29T11:05:35+01:00" level=debug msg="completed challenge" Oct 29 11:05:35 volumio go-librespot[6951]: time="2024-10-29T11:05: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 29 11:05:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 29 11:05:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 29 11:05:37 volumio volumio[1034]: info: Initializing connection to go-librespot Websocket Oct 29 11:05:37 volumio volumio[1034]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 11:05:37 volumio volumio[1034]: info: Selecting previously unselected package fonts-tlwg-garuda-ttf. Oct 29 11:05:37 volumio volumio[1034]: info: Preparing to unpack .../07-fonts-tlwg-garuda-ttf_1%3a0.7.1-1_all.deb ... Oct 29 11:05:38 volumio volumio[1034]: info: Unpacking fonts-tlwg-garuda-ttf (1:0.7.1-1) ... Oct 29 11:05:38 volumio volumio[1034]: info: Selecting previously unselected package fonts-tlwg-kinnari-ttf. Oct 29 11:05:38 volumio volumio[1034]: info: Preparing to unpack .../08-fonts-tlwg-kinnari-ttf_1%3a0.7.1-1_all.deb ... Oct 29 11:05:38 volumio volumio[1034]: info: Unpacking fonts-tlwg-kinnari-ttf (1:0.7.1-1) ... Oct 29 11:05:38 volumio volumio[1034]: info: Selecting previously unselected package fonts-tlwg-laksaman-ttf. Oct 29 11:05:38 volumio volumio[1034]: info: Preparing to unpack .../09-fonts-tlwg-laksaman-ttf_1%3a0.7.1-1_all.deb ... Oct 29 11:05:38 volumio volumio[1034]: info: Unpacking fonts-tlwg-laksaman-ttf (1:0.7.1-1) ... Oct 29 11:05:39 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 29 11:05:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 197. Oct 29 11:05:39 volumio systemd[1]: Stopped go-librespot Daemon. Oct 29 11:05:39 volumio systemd[1]: Started go-librespot Daemon. Oct 29 11:05:39 volumio go-librespot[6986]: Librespot-go daemon starting... Oct 29 11:05:39 volumio go-librespot[6986]: time="2024-10-29T11:05:39+01:00" level=info msg="generated new device id: b86cec0a44dd1fc7bf9483a6c4b97028c1d97703" Oct 29 11:05:39 volumio go-librespot[6986]: time="2024-10-29T11:05:39+01:00" level=debug msg="stored credentials found for 31n3mfaqxn3pbyb6v7nkastad4j4" Oct 29 11:05:39 volumio volumio[1034]: info: Selecting previously unselected package fonts-tlwg-loma-ttf. Oct 29 11:05:39 volumio volumio[1034]: info: Preparing to unpack .../10-fonts-tlwg-loma-ttf_1%3a0.7.1-1_all.deb ... Oct 29 11:05:39 volumio volumio[1034]: info: Unpacking fonts-tlwg-loma-ttf (1:0.7.1-1) ... Oct 29 11:05:39 volumio volumio[1034]: info: Selecting previously unselected package fonts-tlwg-mono-ttf. Oct 29 11:05:39 volumio volumio[1034]: info: Preparing to unpack .../11-fonts-tlwg-mono-ttf_1%3a0.7.1-1_all.deb ... Oct 29 11:05:39 volumio volumio[1034]: info: Unpacking fonts-tlwg-mono-ttf (1:0.7.1-1) ... Oct 29 11:05:40 volumio volumio[1034]: info: Selecting previously unselected package fonts-tlwg-norasi-ttf. Oct 29 11:05:40 volumio go-librespot[6986]: time="2024-10-29T11:05:40+01:00" level=debug msg="obtained new client token: AADby9saPmqc6+7QQ3iNQCyDvEskCDfeT9MqxZGiP0OpozvcwmcfpYFnWM3FW7k0Blty+2n0JNpBizpiphUUt982XmipbLb/3PcGyZ/SwSvn1TaBGWDnhfQZ5mqteGRl5xjVD7q6WMgAmY5dbBhskHX3VsLyhUcL5Ehd9WH9VK90+jsJCLkS0vN22P+JyywZjFwXIu5UNcvNzwba/GhLGeuVgoBih/SN/NNnAF2dU3L/1srpeOlx6vE+hLU7Rr8=" Oct 29 11:05:40 volumio volumio[1034]: info: Initializing connection to go-librespot Websocket Oct 29 11:05:40 volumio go-librespot[6986]: time="2024-10-29T11:05:40+01:00" level=debug msg="new websocket client" Oct 29 11:05:40 volumio volumio[1034]: info: Preparing to unpack .../12-fonts-tlwg-norasi-ttf_1%3a0.7.1-1_all.deb ... Oct 29 11:05:40 volumio volumio[1034]: info: Unpacking fonts-tlwg-norasi-ttf (1:0.7.1-1) ... Oct 29 11:05:40 volumio volumio[1034]: info: Connection to go-librespot Websocket established Oct 29 11:05:40 volumio go-librespot[6986]: time="2024-10-29T11:05:40+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 29 11:05:40 volumio go-librespot[6986]: time="2024-10-29T11:05:40+01:00" level=debug msg="completed keyexchange" Oct 29 11:05:40 volumio volumio[1034]: info: Selecting previously unselected package fonts-tlwg-purisa-ttf. Oct 29 11:05:40 volumio volumio[1034]: info: Preparing to unpack .../13-fonts-tlwg-purisa-ttf_1%3a0.7.1-1_all.deb ... Oct 29 11:05:40 volumio volumio[1034]: info: Unpacking fonts-tlwg-purisa-ttf (1:0.7.1-1) ... Oct 29 11:05:41 volumio go-librespot[6986]: time="2024-10-29T11:05:41+01:00" level=debug msg="completed challenge" Oct 29 11:05:41 volumio go-librespot[6986]: time="2024-10-29T11:05: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" Oct 29 11:05:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 29 11:05:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 29 11:05:41 volumio volumio[1034]: info: Connection to go-librespot Websocket closed Oct 29 11:05:41 volumio volumio[1034]: info: Selecting previously unselected package fonts-tlwg-sawasdee-ttf. Oct 29 11:05:41 volumio volumio[1034]: info: Preparing to unpack .../14-fonts-tlwg-sawasdee-ttf_1%3a0.7.1-1_all.deb ... Oct 29 11:05:41 volumio volumio[1034]: info: Unpacking fonts-tlwg-sawasdee-ttf (1:0.7.1-1) ... Oct 29 11:05:41 volumio volumio[1034]: info: Selecting previously unselected package fonts-tlwg-typewriter-ttf. Oct 29 11:05:41 volumio volumio[1034]: info: Preparing to unpack .../15-fonts-tlwg-typewriter-ttf_1%3a0.7.1-1_all.deb ... Oct 29 11:05:41 volumio volumio[1034]: info: Unpacking fonts-tlwg-typewriter-ttf (1:0.7.1-1) ... Oct 29 11:05:42 volumio volumio[1034]: info: Selecting previously unselected package fonts-tlwg-typist-ttf. Oct 29 11:05:42 volumio volumio[1034]: info: Preparing to unpack .../16-fonts-tlwg-typist-ttf_1%3a0.7.1-1_all.deb ... Oct 29 11:05:42 volumio volumio[1034]: info: Unpacking fonts-tlwg-typist-ttf (1:0.7.1-1) ... Oct 29 11:05:42 volumio volumio[1034]: info: Selecting previously unselected package fonts-tlwg-typo-ttf. Oct 29 11:05:42 volumio volumio[1034]: info: Preparing to unpack .../17-fonts-tlwg-typo-ttf_1%3a0.7.1-1_all.deb ... Oct 29 11:05:42 volumio volumio[1034]: info: Unpacking fonts-tlwg-typo-ttf (1:0.7.1-1) ... Oct 29 11:05:43 volumio volumio[1034]: info: Selecting previously unselected package fonts-tlwg-umpush-ttf. Oct 29 11:05:43 volumio volumio[1034]: info: Preparing to unpack .../18-fonts-tlwg-umpush-ttf_1%3a0.7.1-1_all.deb ... Oct 29 11:05:43 volumio volumio[1034]: info: Unpacking fonts-tlwg-umpush-ttf (1:0.7.1-1) ... Oct 29 11:05:43 volumio volumio[1034]: info: Getting Spotify volume Oct 29 11:05:43 volumio volumio[1034]: (node:1034) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 11:05:43 volumio volumio[1034]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Oct 29 11:05:43 volumio volumio[1034]: (node:1034) 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: 93) Oct 29 11:05:43 volumio volumio[1034]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Oct 29 11:05:43 volumio volumio[1034]: info: CoreCommandRouter::volumioGetState Oct 29 11:05:43 volumio volumio[1034]: info: CorePlayQueue::getTrack 0 Oct 29 11:05:43 volumio volumio[1034]: SPOTIFY: RECEIVED VOLUMIO VOLUME 98 Oct 29 11:05:43 volumio volumio[1034]: info: Selecting previously unselected package fonts-tlwg-waree-ttf. Oct 29 11:05:43 volumio volumio[1034]: info: Preparing to unpack .../19-fonts-tlwg-waree-ttf_1%3a0.7.1-1_all.deb ... Oct 29 11:05:43 volumio volumio[1034]: info: Unpacking fonts-tlwg-waree-ttf (1:0.7.1-1) ... Oct 29 11:05:44 volumio volumio[1034]: info: Initializing connection to go-librespot Websocket Oct 29 11:05:44 volumio volumio[1034]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 11:05:44 volumio volumio[1034]: info: Selecting previously unselected package fonts-thai-tlwg-ttf. Oct 29 11:05:44 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 29 11:05:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 198. Oct 29 11:05:44 volumio systemd[1]: Stopped go-librespot Daemon. Oct 29 11:05:44 volumio volumio[1034]: info: Preparing to unpack .../20-fonts-thai-tlwg-ttf_1%3a0.7.1-1_all.deb ... Oct 29 11:05:44 volumio systemd[1]: Started go-librespot Daemon. Oct 29 11:05:44 volumio go-librespot[7148]: Librespot-go daemon starting... Oct 29 11:05:44 volumio volumio[1034]: info: Unpacking fonts-thai-tlwg-ttf (1:0.7.1-1) ... Oct 29 11:05:44 volumio go-librespot[7148]: time="2024-10-29T11:05:44+01:00" level=info msg="generated new device id: 94380248792fcb932c54f5e63bc2392c3535dab3" Oct 29 11:05:44 volumio go-librespot[7148]: time="2024-10-29T11:05:44+01:00" level=debug msg="stored credentials found for 31n3mfaqxn3pbyb6v7nkastad4j4" Oct 29 11:05:44 volumio volumio[1034]: info: Selecting previously unselected package fonts-tlwg-garuda. Oct 29 11:05:44 volumio volumio[1034]: info: Preparing to unpack .../21-fonts-tlwg-garuda_1%3a0.7.1-1_all.deb ... Oct 29 11:05:44 volumio volumio[1034]: info: Unpacking fonts-tlwg-garuda (1:0.7.1-1) ... Oct 29 11:05:44 volumio go-librespot[7148]: time="2024-10-29T11:05:44+01:00" level=debug msg="obtained new client token: AAAa6EXiYBixvm+E0eQrjR8GvtX5mqGQ1OrYjCA3t1+KlifMmEcI9fiFaRI/9T5Il98H0crzP1tmFnbnlJBNY9XD1IYDfIRfqgy8s4u9K7AcOjReXCe5v4FSJNhVSLGoLCdVqCedodLYDjyWbxPI27YXLyeRUqgkpNefmXIEVC862sscimV0vVlAk+srqXzAnty7Xw+0o52o8nVKOUqWp3rXakUFMYLLAR7NJ6ENTtTzTYNzsA3szRazDZ+4MDKLEw==" Oct 29 11:05:45 volumio go-librespot[7148]: time="2024-10-29T11:05:45+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 29 11:05:45 volumio go-librespot[7148]: time="2024-10-29T11:05:45+01:00" level=debug msg="completed keyexchange" Oct 29 11:05:45 volumio volumio[1034]: info: Selecting previously unselected package fonts-tlwg-kinnari. Oct 29 11:05:45 volumio volumio[1034]: info: Preparing to unpack .../22-fonts-tlwg-kinnari_1%3a0.7.1-1_all.deb ... Oct 29 11:05:45 volumio go-librespot[7148]: time="2024-10-29T11:05:45+01:00" level=debug msg="completed challenge" Oct 29 11:05:45 volumio volumio[1034]: info: Unpacking fonts-tlwg-kinnari (1:0.7.1-1) ... Oct 29 11:05:45 volumio go-librespot[7148]: time="2024-10-29T11:05:45+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 29 11:05:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 29 11:05:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 29 11:05:46 volumio volumio[1034]: info: Selecting previously unselected package fonts-tlwg-laksaman. Oct 29 11:05:46 volumio volumio[1034]: info: Preparing to unpack .../23-fonts-tlwg-laksaman_1%3a0.7.1-1_all.deb ... Oct 29 11:05:46 volumio volumio[1034]: info: Unpacking fonts-tlwg-laksaman (1:0.7.1-1) ... Oct 29 11:05:47 volumio volumio[1034]: info: Initializing connection to go-librespot Websocket Oct 29 11:05:47 volumio volumio[1034]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 11:05:47 volumio volumio[1034]: info: Selecting previously unselected package fonts-tlwg-loma. Oct 29 11:05:47 volumio volumio[1034]: info: Preparing to unpack .../24-fonts-tlwg-loma_1%3a0.7.1-1_all.deb ... Oct 29 11:05:47 volumio volumio[1034]: info: Unpacking fonts-tlwg-loma (1:0.7.1-1) ... Oct 29 11:05:47 volumio volumio[1034]: info: Selecting previously unselected package fonts-tlwg-mono. Oct 29 11:05:47 volumio volumio[1034]: info: Preparing to unpack .../25-fonts-tlwg-mono_1%3a0.7.1-1_all.deb ... Oct 29 11:05:47 volumio volumio[1034]: info: Unpacking fonts-tlwg-mono (1:0.7.1-1) ... Oct 29 11:05:48 volumio volumio[1034]: info: Selecting previously unselected package fonts-tlwg-norasi. Oct 29 11:05:48 volumio volumio[1034]: info: Preparing to unpack .../26-fonts-tlwg-norasi_1%3a0.7.1-1_all.deb ... Oct 29 11:05:48 volumio volumio[1034]: info: Unpacking fonts-tlwg-norasi (1:0.7.1-1) ... Oct 29 11:05:48 volumio volumio[1034]: info: Selecting previously unselected package fonts-tlwg-purisa. Oct 29 11:05:48 volumio volumio[1034]: info: Preparing to unpack .../27-fonts-tlwg-purisa_1%3a0.7.1-1_all.deb ... Oct 29 11:05:48 volumio volumio[1034]: info: Unpacking fonts-tlwg-purisa (1:0.7.1-1) ... Oct 29 11:05:48 volumio volumio[1034]: info: Selecting previously unselected package fonts-tlwg-sawasdee. Oct 29 11:05:48 volumio volumio[1034]: info: Preparing to unpack .../28-fonts-tlwg-sawasdee_1%3a0.7.1-1_all.deb ... Oct 29 11:05:48 volumio volumio[1034]: info: Unpacking fonts-tlwg-sawasdee (1:0.7.1-1) ... Oct 29 11:05:48 volumio volumio[1034]: info: Selecting previously unselected package fonts-tlwg-typewriter. Oct 29 11:05:48 volumio volumio[1034]: info: Preparing to unpack .../29-fonts-tlwg-typewriter_1%3a0.7.1-1_all.deb ... Oct 29 11:05:48 volumio volumio[1034]: info: Unpacking fonts-tlwg-typewriter (1:0.7.1-1) ... Oct 29 11:05:49 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 29 11:05:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 199. Oct 29 11:05:49 volumio systemd[1]: Stopped go-librespot Daemon. Oct 29 11:05:49 volumio volumio[1034]: info: Selecting previously unselected package fonts-tlwg-typist. Oct 29 11:05:49 volumio systemd[1]: Started go-librespot Daemon. Oct 29 11:05:49 volumio go-librespot[7288]: Librespot-go daemon starting... Oct 29 11:05:49 volumio volumio[1034]: info: Preparing to unpack .../30-fonts-tlwg-typist_1%3a0.7.1-1_all.deb ... Oct 29 11:05:49 volumio go-librespot[7288]: time="2024-10-29T11:05:49+01:00" level=info msg="generated new device id: d81f2468c3edeb5c35b233be8092c2e26d21eaea" Oct 29 11:05:49 volumio go-librespot[7288]: time="2024-10-29T11:05:49+01:00" level=debug msg="stored credentials found for 31n3mfaqxn3pbyb6v7nkastad4j4" Oct 29 11:05:49 volumio volumio[1034]: info: Unpacking fonts-tlwg-typist (1:0.7.1-1) ... Oct 29 11:05:49 volumio volumio[1034]: info: Selecting previously unselected package fonts-tlwg-typo. Oct 29 11:05:49 volumio volumio[1034]: info: Preparing to unpack .../31-fonts-tlwg-typo_1%3a0.7.1-1_all.deb ... Oct 29 11:05:49 volumio volumio[1034]: info: Unpacking fonts-tlwg-typo (1:0.7.1-1) ... Oct 29 11:05:49 volumio go-librespot[7288]: time="2024-10-29T11:05:49+01:00" level=debug msg="obtained new client token: AADwBPLkDJuUYH4D1ZD8e7Ycs03SmIRpIKyEdhJqEuYAsQfdEYd56N4ch7Y4VW9whllk8zaUCMK83Y48GE5+v8cavdH57lyb4Scf+arYxogQ6Q5izMrBJXyMeMa86vLGJXPWtK4bFd9zoEX44mC+dSp+/1cxXtcZYer/34t/nW8mAeBI0BXx8hnX5KVRXacPB153tv6/T3He+Jk2Tig/NciOsEWc5EgnJw0MprLkAEW8UNGiyybJADt4dk/SjjIfeg==" Oct 29 11:05:49 volumio volumio[1034]: info: Selecting previously unselected package fonts-tlwg-umpush. Oct 29 11:05:49 volumio volumio[1034]: info: Preparing to unpack .../32-fonts-tlwg-umpush_1%3a0.7.1-1_all.deb ... Oct 29 11:05:49 volumio volumio[1034]: info: Unpacking fonts-tlwg-umpush (1:0.7.1-1) ... Oct 29 11:05:49 volumio go-librespot[7288]: time="2024-10-29T11:05:49+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 29 11:05:50 volumio volumio[1034]: info: Initializing connection to go-librespot Websocket Oct 29 11:05:50 volumio go-librespot[7288]: time="2024-10-29T11:05:50+01:00" level=debug msg="new websocket client" Oct 29 11:05:50 volumio volumio[1034]: info: Connection to go-librespot Websocket established Oct 29 11:05:50 volumio volumio[1034]: info: Selecting previously unselected package fonts-tlwg-waree. Oct 29 11:05:50 volumio go-librespot[7288]: time="2024-10-29T11:05:50+01:00" level=debug msg="completed keyexchange" Oct 29 11:05:50 volumio volumio[1034]: info: Preparing to unpack .../33-fonts-tlwg-waree_1%3a0.7.1-1_all.deb ... Oct 29 11:05:50 volumio volumio[1034]: info: Unpacking fonts-tlwg-waree (1:0.7.1-1) ... Oct 29 11:05:50 volumio go-librespot[7288]: time="2024-10-29T11:05:50+01:00" level=debug msg="completed challenge" Oct 29 11:05:50 volumio go-librespot[7288]: time="2024-10-29T11:05: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" Oct 29 11:05:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 29 11:05:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 29 11:05:50 volumio volumio[1034]: info: Connection to go-librespot Websocket closed Oct 29 11:05:50 volumio volumio[1034]: info: Setting up fonts-tlwg-garuda-ttf (1:0.7.1-1) ... Oct 29 11:05:50 volumio volumio[1034]: info: Setting up fonts-tlwg-laksaman-ttf (1:0.7.1-1) ... Oct 29 11:05:50 volumio volumio[1034]: info: Setting up fonts-unfonts-core (1:1.0.2-080608-16) ... Oct 29 11:05:51 volumio volumio[1034]: info: Setting up fonts-tlwg-loma-ttf (1:0.7.1-1) ... Oct 29 11:05:51 volumio volumio[1034]: info: Setting up fonts-tlwg-typo-ttf (1:0.7.1-1) ... Oct 29 11:05:51 volumio volumio[1034]: info: Setting up fonts-tlwg-kinnari-ttf (1:0.7.1-1) ... Oct 29 11:05:51 volumio volumio[1034]: info: Setting up fonts-arphic-gbsn00lp (2.11-15) ... Oct 29 11:05:51 volumio volumio[1034]: info: Setting up fonts-tlwg-umpush-ttf (1:0.7.1-1) ... Oct 29 11:05:51 volumio volumio[1034]: info: Setting up fonts-tlwg-kinnari (1:0.7.1-1) ... Oct 29 11:05:51 volumio volumio[1034]: info: Setting up fonts-vlgothic (20141206-5) ... Oct 29 11:05:51 volumio volumio[1034]: info: update-alternatives: using /usr/share/fonts/truetype/vlgothic/VL-Gothic-Regular.ttf to provide /usr/share/fonts/truetype/fonts-japanese-gothic.ttf (fonts-japanese-gothic.ttf) in auto mode Oct 29 11:05:51 volumio volumio[1034]: info: Setting up fonts-tlwg-laksaman (1:0.7.1-1) ... Oct 29 11:05:51 volumio volumio[1034]: info: Setting up fonts-tlwg-sawasdee-ttf (1:0.7.1-1) ... Oct 29 11:05:51 volumio volumio[1034]: info: Setting up fonts-tlwg-typist-ttf (1:0.7.1-1) ... Oct 29 11:05:51 volumio volumio[1034]: info: Setting up fonts-tlwg-typewriter-ttf (1:0.7.1-1) ... Oct 29 11:05:51 volumio volumio[1034]: info: Setting up fonts-ipafont-mincho (00303-18) ... Oct 29 11:05:51 volumio volumio[1034]: info: update-alternatives: using /usr/share/fonts/opentype/ipafont-mincho/ipam.ttf to provide /usr/share/fonts/truetype/fonts-japanese-mincho.ttf (fonts-japanese-mincho.ttf) in auto mode Oct 29 11:05:51 volumio volumio[1034]: info: Setting up fonts-ipafont-gothic (00303-18) ... Oct 29 11:05:51 volumio volumio[1034]: info: update-alternatives: using /usr/share/fonts/opentype/ipafont-gothic/ipag.ttf to provide /usr/share/fonts/truetype/fonts-japanese-gothic.ttf (fonts-japanese-gothic.ttf) in auto mode Oct 29 11:05:51 volumio volumio[1034]: info: Setting up fonts-tlwg-garuda (1:0.7.1-1) ... Oct 29 11:05:51 volumio volumio[1034]: info: Setting up fonts-tlwg-norasi-ttf (1:0.7.1-1) ... Oct 29 11:05:51 volumio volumio[1034]: info: Setting up fonts-tlwg-waree-ttf (1:0.7.1-1) ... Oct 29 11:05:52 volumio volumio[1034]: info: Setting up fonts-tlwg-loma (1:0.7.1-1) ... Oct 29 11:05:52 volumio volumio[1034]: info: Setting up fonts-tlwg-purisa-ttf (1:0.7.1-1) ... Oct 29 11:05:52 volumio volumio[1034]: info: Setting up fonts-tlwg-mono-ttf (1:0.7.1-1) ... Oct 29 11:05:52 volumio volumio[1034]: info: Setting up fonts-arphic-ukai (0.2.20080216.2-4) ... Oct 29 11:05:52 volumio volumio[1034]: info: Setting up fonts-tlwg-typewriter (1:0.7.1-1) ... Oct 29 11:05:52 volumio volumio[1034]: info: Setting up fonts-tlwg-typo (1:0.7.1-1) ... Oct 29 11:05:52 volumio volumio[1034]: info: Setting up fonts-tlwg-waree (1:0.7.1-1) ... Oct 29 11:05:52 volumio volumio[1034]: info: Setting up fonts-thai-tlwg-ttf (1:0.7.1-1) ... Oct 29 11:05:52 volumio volumio[1034]: info: Setting up fonts-tlwg-sawasdee (1:0.7.1-1) ... Oct 29 11:05:52 volumio volumio[1034]: info: Setting up fonts-tlwg-typist (1:0.7.1-1) ... Oct 29 11:05:52 volumio volumio[1034]: info: Setting up fonts-tlwg-umpush (1:0.7.1-1) ... Oct 29 11:05:53 volumio volumio[1034]: info: Setting up fonts-ipafont (00303-18) ... Oct 29 11:05:53 volumio volumio[1034]: info: Setting up fonts-tlwg-mono (1:0.7.1-1) ... Oct 29 11:05:53 volumio volumio[1034]: info: Getting Spotify volume Oct 29 11:05:53 volumio volumio[1034]: (node:1034) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 11:05:53 volumio volumio[1034]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Oct 29 11:05:53 volumio volumio[1034]: (node:1034) 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: 94) Oct 29 11:05:53 volumio volumio[1034]: info: Setting up fonts-tlwg-purisa (1:0.7.1-1) ... Oct 29 11:05:53 volumio volumio[1034]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Oct 29 11:05:53 volumio volumio[1034]: info: Setting up fonts-tlwg-norasi (1:0.7.1-1) ... Oct 29 11:05:53 volumio volumio[1034]: info: CoreCommandRouter::volumioGetState Oct 29 11:05:53 volumio volumio[1034]: info: CorePlayQueue::getTrack 0 Oct 29 11:05:53 volumio volumio[1034]: SPOTIFY: RECEIVED VOLUMIO VOLUME 98 Oct 29 11:05:53 volumio volumio[1034]: info: Processing triggers for fontconfig (2.13.1-2) ... Oct 29 11:05:53 volumio volumio[1034]: info: Initializing connection to go-librespot Websocket Oct 29 11:05:53 volumio volumio[1034]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 11:05:53 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 29 11:05:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 200. Oct 29 11:05:53 volumio systemd[1]: Stopped go-librespot Daemon. Oct 29 11:05:53 volumio systemd[1]: Started go-librespot Daemon. Oct 29 11:05:53 volumio go-librespot[7451]: Librespot-go daemon starting... Oct 29 11:05:53 volumio go-librespot[7451]: time="2024-10-29T11:05:53+01:00" level=info msg="generated new device id: 1c395534b749dfaa32b66c386e9fd56251f7810c" Oct 29 11:05:53 volumio go-librespot[7451]: time="2024-10-29T11:05:53+01:00" level=debug msg="stored credentials found for 31n3mfaqxn3pbyb6v7nkastad4j4" Oct 29 11:05:54 volumio go-librespot[7451]: time="2024-10-29T11:05:54+01:00" level=debug msg="obtained new client token: AADd/zoaIzgEYZXt3fIZEmsFh7cSJgOTgXY4s9eo02+rUDfMVdjg9onH9/TIkaWONf1d92bshku7H4g68Z7wgDr13ftpEX1NzsMy1E0Nspw8H+4OOowjv93clSzK1NUV1cF4FgqYzhSlpXLZrguRpMBqIeIwwp1h1Y+bpoUmMu2c4F6dm2U8tt9nIkX3pmKNV4YjZQ3pgr/+GV73cgC4hQu5k65hMtZ37+K8gqP2hQT8jwGEJtH98kJVPf5QeQ3cQA==" Oct 29 11:05:54 volumio go-librespot[7451]: time="2024-10-29T11:05:54+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 29 11:05:54 volumio go-librespot[7451]: time="2024-10-29T11:05:54+01:00" level=debug msg="completed keyexchange" Oct 29 11:05:55 volumio go-librespot[7451]: time="2024-10-29T11:05:55+01:00" level=debug msg="completed challenge" Oct 29 11:05:55 volumio go-librespot[7451]: time="2024-10-29T11:05:55+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 29 11:05:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 29 11:05:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 29 11:05:55 volumio volumio[1034]: info: Creating Kiosk data dir Oct 29 11:05:55 volumio volumio[1034]: info: Creating Volumio kiosk start script Oct 29 11:05:55 volumio volumio[1034]: info: Creating Systemd Unit for Kiosk Oct 29 11:05:55 volumio systemd[1]: Reloading. Oct 29 11:05:56 volumio systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Oct 29 11:05:56 volumio volumio[1034]: info: Initializing connection to go-librespot Websocket Oct 29 11:05:56 volumio volumio[1034]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 11:05:57 volumio volumio[1034]: info: Disabling login prompt Oct 29 11:05:57 volumio systemd[1]: Reloading. Oct 29 11:05:57 volumio systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Oct 29 11:05:58 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 29 11:05:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 201. Oct 29 11:05:58 volumio volumio[1034]: info: Installing Virtual Keyboard Oct 29 11:05:58 volumio systemd[1]: Stopped go-librespot Daemon. Oct 29 11:05:58 volumio systemd[1]: Started go-librespot Daemon. Oct 29 11:05:58 volumio go-librespot[7504]: Librespot-go daemon starting... Oct 29 11:05:58 volumio go-librespot[7504]: time="2024-10-29T11:05:58+01:00" level=info msg="generated new device id: 233a8fbe27ba8a4b58662ca0a0055240c4f969be" Oct 29 11:05:58 volumio go-librespot[7504]: time="2024-10-29T11:05:58+01:00" level=debug msg="stored credentials found for 31n3mfaqxn3pbyb6v7nkastad4j4" Oct 29 11:05:59 volumio go-librespot[7504]: time="2024-10-29T11:05:59+01:00" level=debug msg="obtained new client token: AADyuVF4PFxCLqCUraaj5DEENB5gFMGyrK8sCA7yMifbaqFShegQZ1CxbA6jWoIh6qThcp7HgGxlNT33WoxRAGxl3W0IimtPFcLDSNHyAm76TtX1rteYEDTaV6SxzD6O5YW96WlT8qyhF6wRvBkIoqil+z0t0xDcfnqDujq/R/uLyiJWEc2OEBGi36JLsiV5RjtLhCR+v3rNArH9uRcUraQjkXapgoHkj5con7Ct4Kfw8pva3uWaACE96PkqA6c=" Oct 29 11:05:59 volumio go-librespot[7504]: time="2024-10-29T11:05:59+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 29 11:05:59 volumio go-librespot[7504]: time="2024-10-29T11:05:59+01:00" level=debug msg="completed keyexchange" Oct 29 11:05:59 volumio volumio[1034]: info: Initializing connection to go-librespot Websocket Oct 29 11:05:59 volumio go-librespot[7504]: time="2024-10-29T11:05:59+01:00" level=debug msg="new websocket client" Oct 29 11:05:59 volumio volumio[1034]: info: Connection to go-librespot Websocket established Oct 29 11:06:00 volumio go-librespot[7504]: time="2024-10-29T11:06:00+01:00" level=debug msg="completed challenge" Oct 29 11:06:00 volumio go-librespot[7504]: time="2024-10-29T11:06: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 29 11:06:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 29 11:06:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 29 11:06:00 volumio volumio[1034]: info: Connection to go-librespot Websocket closed Oct 29 11:06:00 volumio volumio[1034]: info: Allowing volumio to start an xsession Oct 29 11:06:00 volumio sudo[3922]: pam_unix(sudo:session): session closed for user root Oct 29 11:06:00 volumio volumio[1034]: info: Install script completed Oct 29 11:06:00 volumio volumio[1034]: info: Adding reference to registry Oct 29 11:06:00 volumio volumio[1034]: info: Done installing plugin. Oct 29 11:06:00 volumio volumio[1034]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 29 11:06:00 volumio volumio[1034]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 29 11:06:00 volumio volumio[1034]: info: Removing temporary directory /tmp/touch_display-iRJbxbTKNk Oct 29 11:06:00 volumio volumio[1034]: Plugin install end detected on script Oct 29 11:06:00 volumio volumio[1034]: info: Folder /tmp/plugins removed Oct 29 11:06:00 volumio volumio[1034]: info: Folder /tmp/downloaded_plugin.zip removed Oct 29 11:06:00 volumio volumio[1034]: info: Folder /data/temp removed Oct 29 11:06:02 volumio volumio[1034]: info: Getting Spotify volume Oct 29 11:06:02 volumio volumio[1034]: (node:1034) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 11:06:02 volumio volumio[1034]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Oct 29 11:06:02 volumio volumio[1034]: (node:1034) 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: 95) Oct 29 11:06:02 volumio volumio[1034]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Oct 29 11:06:02 volumio volumio[1034]: info: CoreCommandRouter::volumioGetState Oct 29 11:06:02 volumio volumio[1034]: info: CorePlayQueue::getTrack 0 Oct 29 11:06:02 volumio volumio[1034]: SPOTIFY: RECEIVED VOLUMIO VOLUME 98 Oct 29 11:06:03 volumio volumio[1034]: info: Initializing connection to go-librespot Websocket Oct 29 11:06:03 volumio volumio[1034]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 11:06:03 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 29 11:06:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 202. Oct 29 11:06:03 volumio systemd[1]: Stopped go-librespot Daemon. Oct 29 11:06:03 volumio systemd[1]: Started go-librespot Daemon. Oct 29 11:06:03 volumio go-librespot[7524]: Librespot-go daemon starting... Oct 29 11:06:03 volumio go-librespot[7524]: time="2024-10-29T11:06:03+01:00" level=info msg="generated new device id: 8be0f66c979533d8dd6d8f2d61ff698e980ebf34" Oct 29 11:06:03 volumio go-librespot[7524]: time="2024-10-29T11:06:03+01:00" level=debug msg="stored credentials found for 31n3mfaqxn3pbyb6v7nkastad4j4" Oct 29 11:06:03 volumio go-librespot[7524]: time="2024-10-29T11:06:03+01:00" level=debug msg="obtained new client token: AADLzj+J5mdSrkmMCq32u+ceQ9XknSnNuBfWEri5RC5Th/vSKYgN+pOZhGprWXo2eiGuAU9PqmXtG6gZrT/ho9ksvx8yye1CChvNE5QOF40TJNKQIQeejwFpAofY/Q8mlFYu1ZisyKZ5u5iD51YXlXUlY23tLWpOxDX6stH2avDW5oafEgsdJsXcb72d+jBCz9FuMJRVCI4TMivjWmoNU8713aOHGdehlZ/wmTkqFm6LSs2nDma0PP+ytzQGrAatQg==" Oct 29 11:06:04 volumio go-librespot[7524]: time="2024-10-29T11:06: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 29 11:06:04 volumio go-librespot[7524]: time="2024-10-29T11:06:04+01:00" level=debug msg="completed keyexchange" Oct 29 11:06:04 volumio go-librespot[7524]: time="2024-10-29T11:06:04+01:00" level=debug msg="completed challenge" Oct 29 11:06:04 volumio go-librespot[7524]: time="2024-10-29T11:06: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 29 11:06:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 29 11:06:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 29 11:06:06 volumio volumio[1034]: info: Initializing connection to go-librespot Websocket Oct 29 11:06:06 volumio volumio[1034]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 11:06:08 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 29 11:06:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 203. Oct 29 11:06:08 volumio systemd[1]: Stopped go-librespot Daemon. Oct 29 11:06:08 volumio systemd[1]: Started go-librespot Daemon. Oct 29 11:06:08 volumio go-librespot[7532]: Librespot-go daemon starting... Oct 29 11:06:08 volumio go-librespot[7532]: time="2024-10-29T11:06:08+01:00" level=info msg="generated new device id: f2b42e279c57fd810acfb4abaf11d825a1aa9fc2" Oct 29 11:06:08 volumio go-librespot[7532]: time="2024-10-29T11:06:08+01:00" level=debug msg="stored credentials found for 31n3mfaqxn3pbyb6v7nkastad4j4" Oct 29 11:06:08 volumio go-librespot[7532]: time="2024-10-29T11:06:08+01:00" level=debug msg="obtained new client token: AAC/2/RJyCUUGn0w8VHnpoIz0pVsmYxJjlaGhGkxKODb7XbhlD/KoQ4r1bmX6IEEuc+ut+3Xyy7YEJQd0MWFgA+SYz5OQHvMoQccok4QEENUezV5wS3MDqTpB6kQUjii+LQ5q+4whLFpwAIuAOtkMI6FlmHsp37Vj+QxbDGl8dDIzuQubCzHtTOfwivaQdqrmHfssZJv36CLbjfavDRLOADqqedQGvQeJ1jtRYj+s3GEQmbukMPgTTDhdHKN1ruMdw==" Oct 29 11:06:08 volumio go-librespot[7532]: time="2024-10-29T11:06:08+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 29 11:06:09 volumio go-librespot[7532]: time="2024-10-29T11:06:09+01:00" level=debug msg="completed keyexchange" Oct 29 11:06:09 volumio volumio[1034]: info: Initializing connection to go-librespot Websocket Oct 29 11:06:09 volumio go-librespot[7532]: time="2024-10-29T11:06:09+01:00" level=debug msg="new websocket client" Oct 29 11:06:09 volumio volumio[1034]: info: Connection to go-librespot Websocket established Oct 29 11:06:09 volumio go-librespot[7532]: time="2024-10-29T11:06:09+01:00" level=debug msg="completed challenge" Oct 29 11:06:09 volumio go-librespot[7532]: time="2024-10-29T11:06:09+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 29 11:06:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 29 11:06:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 29 11:06:09 volumio volumio[1034]: info: Connection to go-librespot Websocket closed Oct 29 11:06:12 volumio volumio[1034]: info: Getting Spotify volume Oct 29 11:06:12 volumio volumio[1034]: (node:1034) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 11:06:12 volumio volumio[1034]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Oct 29 11:06:12 volumio volumio[1034]: (node:1034) 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: 96) Oct 29 11:06:12 volumio volumio[1034]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Oct 29 11:06:12 volumio volumio[1034]: info: CoreCommandRouter::volumioGetState Oct 29 11:06:12 volumio volumio[1034]: info: CorePlayQueue::getTrack 0 Oct 29 11:06:12 volumio volumio[1034]: SPOTIFY: RECEIVED VOLUMIO VOLUME 98 Oct 29 11:06:12 volumio volumio[1034]: info: Initializing connection to go-librespot Websocket Oct 29 11:06:12 volumio volumio[1034]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 11:06:12 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 29 11:06:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 204. Oct 29 11:06:12 volumio systemd[1]: Stopped go-librespot Daemon. Oct 29 11:06:12 volumio systemd[1]: Started go-librespot Daemon. Oct 29 11:06:12 volumio go-librespot[7541]: Librespot-go daemon starting... Oct 29 11:06:12 volumio go-librespot[7541]: time="2024-10-29T11:06:12+01:00" level=info msg="generated new device id: 46c04ad8a4153d484b5474a306578fc57508eaf4" Oct 29 11:06:12 volumio go-librespot[7541]: time="2024-10-29T11:06:12+01:00" level=debug msg="stored credentials found for 31n3mfaqxn3pbyb6v7nkastad4j4" Oct 29 11:06:13 volumio go-librespot[7541]: time="2024-10-29T11:06:13+01:00" level=debug msg="obtained new client token: AAD0PB03PPZoC70LcIcj9S59lVKcsoWK/wKYpUjcpBGdWll/4JQxdTgFsJ7LtIoQ0ZYlkGkiYebJujGchSvgcln/iI+GZ+OOUZChrwtCgsq6/gYGWLSOW3ECCkR9y1QgXOlYTqk4o1MTaOvCu/W1AbChSrHRldiM3kniV8rBCvu/dVuL0cnvXXmCORFWzj4Y3k5zxmfpHGMxZWq0rn+ESqsrgXHcK7ay8PFX9S6EyeUgypxkQjzqWzUYMem+t6cxSA==" Oct 29 11:06:13 volumio go-librespot[7541]: time="2024-10-29T11:06:13+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 29 11:06:13 volumio go-librespot[7541]: time="2024-10-29T11:06:13+01:00" level=debug msg="completed keyexchange" Oct 29 11:06:14 volumio go-librespot[7541]: time="2024-10-29T11:06:14+01:00" level=debug msg="completed challenge" Oct 29 11:06:14 volumio go-librespot[7541]: time="2024-10-29T11:06:14+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 29 11:06:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 29 11:06:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 29 11:06:15 volumio volumio[1034]: info: Initializing connection to go-librespot Websocket Oct 29 11:06:15 volumio volumio[1034]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 11:06:17 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 29 11:06:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 205. Oct 29 11:06:17 volumio systemd[1]: Stopped go-librespot Daemon. Oct 29 11:06:17 volumio systemd[1]: Started go-librespot Daemon. Oct 29 11:06:17 volumio go-librespot[7549]: Librespot-go daemon starting... Oct 29 11:06:17 volumio go-librespot[7549]: time="2024-10-29T11:06:17+01:00" level=info msg="generated new device id: 5880899757c3a8771029f0763cc36272ef266bf3" Oct 29 11:06:17 volumio go-librespot[7549]: time="2024-10-29T11:06:17+01:00" level=debug msg="stored credentials found for 31n3mfaqxn3pbyb6v7nkastad4j4" Oct 29 11:06:18 volumio go-librespot[7549]: time="2024-10-29T11:06:18+01:00" level=debug msg="obtained new client token: AAD5oA1onq/NHhFOzyxy8o7LybxHNlzFNQjwOEL1RR+1g9jJyoB0NTFazDt4wV3T7V2G+NDZy2L8hD5zW894huxus++fJRnLDNpQ5nzKv08R9fJvzU2ZVAS+XlNH7K54xPK2Hz5vyZn3kIQ8bvMEf8HliPIJJFboqcTf/8sYxUalN0YLAMel4StavAzwfskooqih5Rj2rshGVX0kjcu9ugkSINM9+GYAHoWiX/v54N6SlB0qLicfG9msqnFs1+0=" Oct 29 11:06:18 volumio go-librespot[7549]: time="2024-10-29T11:06:18+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 29 11:06:18 volumio volumio[1034]: info: Initializing connection to go-librespot Websocket Oct 29 11:06:18 volumio go-librespot[7549]: time="2024-10-29T11:06:18+01:00" level=debug msg="new websocket client" Oct 29 11:06:18 volumio go-librespot[7549]: time="2024-10-29T11:06:18+01:00" level=debug msg="completed keyexchange" Oct 29 11:06:18 volumio volumio[1034]: info: Connection to go-librespot Websocket established Oct 29 11:06:19 volumio go-librespot[7549]: time="2024-10-29T11:06:19+01:00" level=debug msg="completed challenge" Oct 29 11:06:19 volumio go-librespot[7549]: time="2024-10-29T11:06:19+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 29 11:06:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 29 11:06:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 29 11:06:19 volumio volumio[1034]: info: Connection to go-librespot Websocket closed Oct 29 11:06:21 volumio volumio[1034]: info: Getting Spotify volume Oct 29 11:06:21 volumio volumio[1034]: (node:1034) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 11:06:21 volumio volumio[1034]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Oct 29 11:06:21 volumio volumio[1034]: (node:1034) 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: 97) Oct 29 11:06:21 volumio volumio[1034]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Oct 29 11:06:21 volumio volumio[1034]: info: CoreCommandRouter::volumioGetState Oct 29 11:06:21 volumio volumio[1034]: info: CorePlayQueue::getTrack 0 Oct 29 11:06:21 volumio volumio[1034]: SPOTIFY: RECEIVED VOLUMIO VOLUME 98 Oct 29 11:06:22 volumio volumio[1034]: info: Initializing connection to go-librespot Websocket Oct 29 11:06:22 volumio volumio[1034]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 11:06:22 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 29 11:06:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 206. Oct 29 11:06:22 volumio systemd[1]: Stopped go-librespot Daemon. Oct 29 11:06:22 volumio systemd[1]: Started go-librespot Daemon. Oct 29 11:06:22 volumio go-librespot[7557]: Librespot-go daemon starting... Oct 29 11:06:22 volumio go-librespot[7557]: time="2024-10-29T11:06:22+01:00" level=info msg="generated new device id: 61210c2ef36a82f198c4704c8eecc35c11698edb" Oct 29 11:06:22 volumio go-librespot[7557]: time="2024-10-29T11:06:22+01:00" level=debug msg="stored credentials found for 31n3mfaqxn3pbyb6v7nkastad4j4" Oct 29 11:06:22 volumio go-librespot[7557]: time="2024-10-29T11:06:22+01:00" level=debug msg="obtained new client token: AACnzovWUUNwZl8bweaLbEUNA0EIGRobjTgT6Eur7wSKVmoBuUYSJgiNgnHc10Iu0fk3Am+xT3hup5Fu6FzRXSPveGQ/3sGJnv32dbIqs/HKdRo5uvEy6WXqpVUCMzaxgM/rds1vItaHeqHMeGJ33kdBs9oRD71HRPP+1MwRSbguQdlGX/s2uO3SlgY2LNqZrdnlTWXHIWMJA3/ttUYcyuflbrRFZVo2Dn/SNywx1oK6Q08x9Nr1BawcyK2e9lecoA==" Oct 29 11:06:23 volumio go-librespot[7557]: time="2024-10-29T11:06: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 29 11:06:23 volumio go-librespot[7557]: time="2024-10-29T11:06:23+01:00" level=debug msg="completed keyexchange" Oct 29 11:06:23 volumio go-librespot[7557]: time="2024-10-29T11:06:23+01:00" level=debug msg="completed challenge" Oct 29 11:06:23 volumio go-librespot[7557]: time="2024-10-29T11:06: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 29 11:06:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 29 11:06:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 29 11:06:25 volumio volumio[1034]: info: Initializing connection to go-librespot Websocket Oct 29 11:06:25 volumio volumio[1034]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 11:06:27 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 29 11:06:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 207. Oct 29 11:06:27 volumio systemd[1]: Stopped go-librespot Daemon. Oct 29 11:06:27 volumio systemd[1]: Started go-librespot Daemon. Oct 29 11:06:27 volumio go-librespot[7565]: Librespot-go daemon starting... Oct 29 11:06:27 volumio go-librespot[7565]: time="2024-10-29T11:06:27+01:00" level=info msg="generated new device id: 5e6a68079a962430f7e062710204ac8493ca64e2" Oct 29 11:06:27 volumio go-librespot[7565]: time="2024-10-29T11:06:27+01:00" level=debug msg="stored credentials found for 31n3mfaqxn3pbyb6v7nkastad4j4" Oct 29 11:06:27 volumio go-librespot[7565]: time="2024-10-29T11:06:27+01:00" level=debug msg="obtained new client token: AAAjpYvARhegRHZ1skAXqt/fhlfUUQxkUjBWaYW97H9jHq9bnqLZxuOj9OvP5rzLEW7fAhwW5AU/Bp3s/URm2/LDkcL7MgS5HFrxy5Xqg3AfzS6xopQdVjwG1xc1jjUFMIkfcIBCHZQmbFx4rLfu8Er/795uXree2Y0WoqkvN9qowU8tRoW8fFE6LY/f3VyhlQoDNZteiz+a6yLeEBSzC4fCyfVg7CdPMV3aNMAp4zjy5TK3c9O8sTdUz3eGWS+apw==" Oct 29 11:06:27 volumio go-librespot[7565]: time="2024-10-29T11:06: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-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Oct 29 11:06:28 volumio go-librespot[7565]: time="2024-10-29T11:06:28+01:00" level=debug msg="completed keyexchange" Oct 29 11:06:28 volumio volumio[1034]: info: Initializing connection to go-librespot Websocket Oct 29 11:06:28 volumio go-librespot[7565]: time="2024-10-29T11:06:28+01:00" level=debug msg="new websocket client" Oct 29 11:06:28 volumio volumio[1034]: info: Connection to go-librespot Websocket established Oct 29 11:06:28 volumio go-librespot[7565]: time="2024-10-29T11:06:28+01:00" level=debug msg="completed challenge" Oct 29 11:06:28 volumio go-librespot[7565]: time="2024-10-29T11:06:28+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 29 11:06:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 29 11:06:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 29 11:06:28 volumio volumio[1034]: info: Connection to go-librespot Websocket closed Oct 29 11:06:31 volumio volumio[1034]: info: Getting Spotify volume Oct 29 11:06:31 volumio volumio[1034]: (node:1034) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 11:06:31 volumio volumio[1034]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Oct 29 11:06:31 volumio volumio[1034]: (node:1034) 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: 98) Oct 29 11:06:31 volumio volumio[1034]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Oct 29 11:06:31 volumio volumio[1034]: info: CoreCommandRouter::volumioGetState Oct 29 11:06:31 volumio volumio[1034]: info: CorePlayQueue::getTrack 0 Oct 29 11:06:31 volumio volumio[1034]: SPOTIFY: RECEIVED VOLUMIO VOLUME 98 Oct 29 11:06:31 volumio volumio[1034]: info: Initializing connection to go-librespot Websocket Oct 29 11:06:31 volumio volumio[1034]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 11:06:31 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 29 11:06:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 208. Oct 29 11:06:31 volumio systemd[1]: Stopped go-librespot Daemon. Oct 29 11:06:31 volumio systemd[1]: Started go-librespot Daemon. Oct 29 11:06:31 volumio go-librespot[7573]: Librespot-go daemon starting... Oct 29 11:06:31 volumio go-librespot[7573]: time="2024-10-29T11:06:31+01:00" level=info msg="generated new device id: d7372f226539c9f561c0009bf76bec5d0e4c96d0" Oct 29 11:06:31 volumio go-librespot[7573]: time="2024-10-29T11:06:31+01:00" level=debug msg="stored credentials found for 31n3mfaqxn3pbyb6v7nkastad4j4" Oct 29 11:06:32 volumio go-librespot[7573]: time="2024-10-29T11:06:32+01:00" level=debug msg="obtained new client token: AAAvleG4PL04Af4MysPsnE/BCd9GzyFZlhh0Aw8CQM3NI+nblKMao+eyndqq4goIarO8IzLZpYUr6s/oDNAepwscA7urhRIrdGNfBiIVUfp8R+8D+8bdeFItwLWnaGTlq/KCfpvlkYsuaSwSYtOdr2t7Ect4fnia7qSoaZPoDZA5ljyhwHTZGFcOvqZeZ8werCePY1LxT9st7tRUGW7mzMOiOM1WJg1n7a78F+UbU+IkTDARNcTvto5xuvXN6ao3CA==" Oct 29 11:06:32 volumio go-librespot[7573]: time="2024-10-29T11:06:32+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 29 11:06:32 volumio go-librespot[7573]: time="2024-10-29T11:06:32+01:00" level=debug msg="completed keyexchange" Oct 29 11:06:33 volumio go-librespot[7573]: time="2024-10-29T11:06:33+01:00" level=debug msg="completed challenge" Oct 29 11:06:33 volumio go-librespot[7573]: time="2024-10-29T11:06: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" Oct 29 11:06:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 29 11:06:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 29 11:06:34 volumio volumio[1034]: info: Initializing connection to go-librespot Websocket Oct 29 11:06:34 volumio volumio[1034]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 11:06:36 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 29 11:06:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 209. Oct 29 11:06:36 volumio systemd[1]: Stopped go-librespot Daemon. Oct 29 11:06:36 volumio systemd[1]: Started go-librespot Daemon. Oct 29 11:06:36 volumio go-librespot[7582]: Librespot-go daemon starting... Oct 29 11:06:36 volumio go-librespot[7582]: time="2024-10-29T11:06:36+01:00" level=info msg="generated new device id: d52603cc42fc0473ab9a230aad23487d488bbdd7" Oct 29 11:06:36 volumio go-librespot[7582]: time="2024-10-29T11:06:36+01:00" level=debug msg="stored credentials found for 31n3mfaqxn3pbyb6v7nkastad4j4" Oct 29 11:06:37 volumio go-librespot[7582]: time="2024-10-29T11:06:37+01:00" level=debug msg="obtained new client token: AADyT2bEA1OFgTJhXzWqE4FYSV0MtGy1/XuVTqsdmfscnQ29FENTJz6XqvFX90blUYg6GwZQEjho20x7zx3FSyHvpavkquFaAJ2lOxK8GYzXmFgdmQs5c8qnhwpn9njHMtBIMtmrodzk7Yui527EXmbhxRv+Qm8giZ6hTSyh95lMCC5XqmBSgQg8QA93rb06YcViT43jCtduykHpoQiUqp+kGrXBA+DmA91W0T051o9wCXMAChhOtRLiIS0hcYU=" Oct 29 11:06:37 volumio go-librespot[7582]: time="2024-10-29T11:06:37+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 29 11:06:37 volumio go-librespot[7582]: time="2024-10-29T11:06:37+01:00" level=debug msg="completed keyexchange" Oct 29 11:06:37 volumio volumio[1034]: info: Initializing connection to go-librespot Websocket Oct 29 11:06:37 volumio go-librespot[7582]: time="2024-10-29T11:06:37+01:00" level=debug msg="new websocket client" Oct 29 11:06:37 volumio volumio[1034]: info: Connection to go-librespot Websocket established Oct 29 11:06:38 volumio go-librespot[7582]: time="2024-10-29T11:06:38+01:00" level=debug msg="completed challenge" Oct 29 11:06:38 volumio go-librespot[7582]: time="2024-10-29T11:06:38+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 29 11:06:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 29 11:06:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 29 11:06:38 volumio volumio[1034]: info: Connection to go-librespot Websocket closed Oct 29 11:06:40 volumio volumio[1034]: info: Getting Spotify volume Oct 29 11:06:40 volumio volumio[1034]: (node:1034) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 11:06:40 volumio volumio[1034]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Oct 29 11:06:40 volumio volumio[1034]: (node:1034) 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: 99) Oct 29 11:06:40 volumio volumio[1034]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Oct 29 11:06:40 volumio volumio[1034]: info: CoreCommandRouter::volumioGetState Oct 29 11:06:40 volumio volumio[1034]: info: CorePlayQueue::getTrack 0 Oct 29 11:06:40 volumio volumio[1034]: SPOTIFY: RECEIVED VOLUMIO VOLUME 98 Oct 29 11:06:41 volumio volumio[1034]: info: Initializing connection to go-librespot Websocket Oct 29 11:06:41 volumio volumio[1034]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 29 11:06:41 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 29 11:06:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 210. Oct 29 11:06:41 volumio systemd[1]: Stopped go-librespot Daemon. Oct 29 11:06:41 volumio systemd[1]: Started go-librespot Daemon. Oct 29 11:06:41 volumio go-librespot[7590]: Librespot-go daemon starting... Oct 29 11:06:41 volumio go-librespot[7590]: time="2024-10-29T11:06:41+01:00" level=info msg="generated new device id: a942d026fe65d0e00da1d08eedf1c980a348487d" Oct 29 11:06:41 volumio go-librespot[7590]: time="2024-10-29T11:06:41+01:00" level=debug msg="stored credentials found for 31n3mfaqxn3pbyb6v7nkastad4j4" Oct 29 11:06:41 volumio go-librespot[7590]: time="2024-10-29T11:06:41+01:00" level=debug msg="obtained new client token: AAC4Yw+N7/E9pIsght8KAMyQ/IJZwr7/3DVtETjzXjiCk7PW0RqKOXIIeArzv85hTx3qNdL6z7EB19Qrv0mdRM1oqLY+lNVyf2p3ScNde7UgvpUTxRZArJIkJVv+RBDWpu5MAtmJiwIPR9lEf0b4aLzu1Ojc6git3OGJqLVhn2g/pgcGiJM4h4hhLAQu4Evy+ahiUYeB+kxWgo07EjnuCrIDpO44teKZfB0yAqOIFIZmdy0MkUGlv4de+qZBdVcj+Q==" Oct 29 11:06:42 volumio go-librespot[7590]: time="2024-10-29T11:06:42+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 29 11:06:42 volumio go-librespot[7590]: time="2024-10-29T11:06:42+01:00" level=debug msg="completed keyexchange" Oct 29 11:06:42 volumio volumio[1034]: info: Enabling plugin touch_display Oct 29 11:06:42 volumio volumio[1034]: info: Loading plugin "touch_display"... Oct 29 11:06:42 volumio volumio[1034]: info: PLUGIN START: touch_display Oct 29 11:06:42 volumio volumio[1034]: info: Loading i18n strings for locale en Oct 29 11:06:42 volumio volumio[1034]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 29 11:06:42 volumio sudo[7600]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop getty@tty1.service Oct 29 11:06:42 volumio sudo[7600]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 29 11:06:42 volumio sudo[7602]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl disable getty@tty1.service Oct 29 11:06:42 volumio sudo[7602]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 29 11:06:42 volumio volumio[1034]: info: touch_display: Backlight interface detected. Oct 29 11:06:42 volumio systemd[1]: Stopping Getty on tty1... Oct 29 11:06:42 volumio sudo[7605]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Oct 29 11:06:42 volumio systemd[1]: getty@tty1.service: Main process exited, code=killed, status=15/TERM Oct 29 11:06:42 volumio systemd[1]: getty@tty1.service: Succeeded. Oct 29 11:06:42 volumio systemd[1]: Stopped Getty on tty1. Oct 29 11:06:42 volumio sudo[7605]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 29 11:06:42 volumio volumio[1034]: info: touch_display: Raspberry Pi Foundation touch screen detected. Oct 29 11:06:42 volumio sudo[7609]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/99-vc4.conf Oct 29 11:06:42 volumio sudo[7609]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 29 11:06:42 volumio sudo[7609]: pam_unix(sudo:session): session closed for user root Oct 29 11:06:42 volumio volumio[1034]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/99-vc4.conf set. Oct 29 11:06:42 volumio sudo[7600]: pam_unix(sudo:session): session closed for user root Oct 29 11:06:42 volumio systemd[1]: Reloading. Oct 29 11:06:42 volumio sudo[7612]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod a+w /sys/class/backlight/rpi_backlight/brightness Oct 29 11:06:42 volumio sudo[7612]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 29 11:06:42 volumio volumio[1034]: info: touch_display: systemctl stop getty@tty1.service succeeded. Oct 29 11:06:42 volumio sudo[7612]: pam_unix(sudo:session): session closed for user root Oct 29 11:06:42 volumio volumio[1034]: info: touch_display: File permissions for backlight brightness control set. Oct 29 11:06:42 volumio volumio[1034]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 29 11:06:42 volumio go-librespot[7590]: time="2024-10-29T11:06:42+01:00" level=debug msg="completed challenge" Oct 29 11:06:42 volumio volumio[1034]: TypeError: Cannot read property 'toString' of undefined Oct 29 11:06:42 volumio volumio[1034]: at TouchDisplay.setBrightness (/data/plugins/user_interface/touch_display/index.js:807:56) Oct 29 11:06:42 volumio volumio[1034]: at /data/plugins/user_interface/touch_display/index.js:1373:20 Oct 29 11:06:42 volumio volumio[1034]: at ChildProcess.exithandler (child_process.js:299:7) Oct 29 11:06:42 volumio volumio[1034]: at ChildProcess.emit (events.js:315:20) Oct 29 11:06:42 volumio volumio[1034]: at maybeClose (internal/child_process.js:1048:16) Oct 29 11:06:42 volumio volumio[1034]: at Process.ChildProcess._handle.onexit (internal/child_process.js:288:5) Oct 29 11:06:42 volumio volumio[1034]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 29 11:06:42 volumio go-librespot[7590]: time="2024-10-29T11:06:42+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 29 11:06:43 volumio systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Oct 29 11:06:44 volumio sudo[7692]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-29 11:05 Oct 29 11:06:44 volumio sudo[7692]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 29 11:06:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 29 11:06:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 29 11:06:44 volumio sudo[7605]: pam_unix(sudo:session): session closed for user root Oct 29 11:06:44 volumio systemd[1]: Reloading. 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"