-- Logs begin at Mon 2024-10-07 10:38:43 CST, end at Mon 2024-10-07 13:15:03 CST. -- Oct 07 13:14:00 volumio go-librespot[16128]: time="2024-10-07T13:14:00+08:00" level=debug msg="completed challenge" Oct 07 13:14:00 volumio go-librespot[16128]: time="2024-10-07T13:14:00+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 07 13:14:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 07 13:14:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 07 13:14:01 volumio volumio[928]: info: Initializing connection to go-librespot Websocket Oct 07 13:14:01 volumio volumio[928]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 07 13:14:03 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 07 13:14:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13994. Oct 07 13:14:03 volumio systemd[1]: Stopped go-librespot Daemon. Oct 07 13:14:03 volumio systemd[1]: Started go-librespot Daemon. Oct 07 13:14:03 volumio go-librespot[16174]: Librespot-go daemon starting... Oct 07 13:14:03 volumio go-librespot[16174]: time="2024-10-07T13:14:03+08:00" level=info msg="generated new device id: 8ec39b82cab855a89404fdfcf66c2291ea6e3e02" Oct 07 13:14:03 volumio go-librespot[16174]: time="2024-10-07T13:14:03+08:00" level=debug msg="stored credentials not found" Oct 07 13:14:04 volumio volumio[928]: info: Initializing connection to go-librespot Websocket Oct 07 13:14:04 volumio go-librespot[16174]: time="2024-10-07T13:14:04+08:00" level=debug msg="new websocket client" Oct 07 13:14:04 volumio volumio[928]: info: Connection to go-librespot Websocket established Oct 07 13:14:04 volumio go-librespot[16174]: time="2024-10-07T13:14:04+08:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 07 13:14:04 volumio go-librespot[16174]: time="2024-10-07T13:14:04+08:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 07 13:14:04 volumio go-librespot[16174]: time="2024-10-07T13:14:04+08:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 07 13:14:04 volumio go-librespot[16174]: time="2024-10-07T13:14:04+08:00" level=debug msg="zeroconf server listening on port 41263" Oct 07 13:14:04 volumio go-librespot[16174]: time="2024-10-07T13:14:04+08:00" level=debug msg="obtained new client token: AAAIHkPD+CCvJpI9hJ67Mlj1eP5BhidssPstFRoIXdhYpFiIs26zK23R4Dd3R6dSbe9kFRLd4AYiR/MTrTK/+r3/2vUKUl5XTW2mOmlyoVuL+m1TW5W6fbgKkdh/aHI9LYPGNET0HPee94D77MchH6V6vwcRnTxA7YYs2yomJQpj+ms0hJ1AY5DiOKPOGZoOKJg4aHSafEzSXT6purJVWu2bxFBPUJ58rZ8omwKnveoyePCZuZPgZh6qG1k=" Oct 07 13:14:05 volumio go-librespot[16174]: time="2024-10-07T13:14:05+08:00" level=debug msg="completed keyexchange" Oct 07 13:14:05 volumio go-librespot[16174]: time="2024-10-07T13:14:05+08:00" level=debug msg="completed challenge" Oct 07 13:14:06 volumio go-librespot[16174]: time="2024-10-07T13:14:06+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 07 13:14:06 volumio volumio[928]: info: Connection to go-librespot Websocket closed Oct 07 13:14:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 07 13:14:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 07 13:14:07 volumio volumio[928]: info: Getting Spotify volume Oct 07 13:14:07 volumio volumio[928]: (node:928) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 07 13:14:07 volumio volumio[928]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Oct 07 13:14:07 volumio volumio[928]: (node:928) 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: 6986) Oct 07 13:14:07 volumio volumio[928]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Oct 07 13:14:07 volumio volumio[928]: info: CoreCommandRouter::volumioGetState Oct 07 13:14:07 volumio volumio[928]: info: CorePlayQueue::getTrack 7 Oct 07 13:14:09 volumio volumio[928]: info: Initializing connection to go-librespot Websocket Oct 07 13:14:09 volumio volumio[928]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 07 13:14:09 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 07 13:14:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13995. Oct 07 13:14:09 volumio systemd[1]: Stopped go-librespot Daemon. Oct 07 13:14:09 volumio systemd[1]: Started go-librespot Daemon. Oct 07 13:14:09 volumio go-librespot[16183]: Librespot-go daemon starting... Oct 07 13:14:09 volumio go-librespot[16183]: time="2024-10-07T13:14:09+08:00" level=info msg="generated new device id: 3a126edb5e485befffa7600919283a0c3ed42734" Oct 07 13:14:09 volumio go-librespot[16183]: time="2024-10-07T13:14:09+08:00" level=debug msg="stored credentials not found" Oct 07 13:14:09 volumio go-librespot[16183]: time="2024-10-07T13:14:09+08:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 07 13:14:09 volumio go-librespot[16183]: time="2024-10-07T13:14:09+08:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 07 13:14:09 volumio go-librespot[16183]: time="2024-10-07T13:14:09+08:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 07 13:14:09 volumio go-librespot[16183]: time="2024-10-07T13:14:09+08:00" level=debug msg="zeroconf server listening on port 41515" Oct 07 13:14:10 volumio go-librespot[16183]: time="2024-10-07T13:14:10+08:00" level=debug msg="obtained new client token: AABWzcQlJYEIRLCPBRh9yPtVQRXmDCtCZMgQJWnWWP6wDCQ+WLyCoT+cCzWebHMrJTV8uDUtUOtbA1gZqknLLCFtRMTcxuPeOpJc4fT0+LUyfV8sRwiONxGsjbuUTO4IYx/7J9MAEXhEfaBiruorc7vqF1LSM8L6exwPgg6hn4L3wJ/hkkBbsEcxvge+9g2ABlKO2GY8My7/Ro30+L7FzLmCEx9z1Oi/LPjdC6UhUUVO0zKvMYciLa/Ok/w=" Oct 07 13:14:10 volumio go-librespot[16183]: time="2024-10-07T13:14:10+08:00" level=debug msg="completed keyexchange" Oct 07 13:14:11 volumio go-librespot[16183]: time="2024-10-07T13:14:11+08:00" level=debug msg="completed challenge" Oct 07 13:14:11 volumio go-librespot[16183]: time="2024-10-07T13:14:11+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 07 13:14:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 07 13:14:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 07 13:14:12 volumio volumio[928]: info: Initializing connection to go-librespot Websocket Oct 07 13:14:12 volumio volumio[928]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 07 13:14:14 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 07 13:14:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13996. Oct 07 13:14:14 volumio systemd[1]: Stopped go-librespot Daemon. Oct 07 13:14:14 volumio systemd[1]: Started go-librespot Daemon. Oct 07 13:14:14 volumio go-librespot[16192]: Librespot-go daemon starting... Oct 07 13:14:15 volumio go-librespot[16192]: time="2024-10-07T13:14:15+08:00" level=info msg="generated new device id: 534032589520063bc74b5f1c8e5b4f1d4183413c" Oct 07 13:14:15 volumio go-librespot[16192]: time="2024-10-07T13:14:15+08:00" level=debug msg="stored credentials not found" Oct 07 13:14:15 volumio volumio[928]: info: Initializing connection to go-librespot Websocket Oct 07 13:14:15 volumio go-librespot[16192]: time="2024-10-07T13:14:15+08:00" level=debug msg="new websocket client" Oct 07 13:14:15 volumio volumio[928]: info: Connection to go-librespot Websocket established Oct 07 13:14:15 volumio go-librespot[16192]: time="2024-10-07T13:14:15+08:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 07 13:14:15 volumio go-librespot[16192]: time="2024-10-07T13:14:15+08:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 07 13:14:15 volumio go-librespot[16192]: time="2024-10-07T13:14:15+08:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 07 13:14:15 volumio go-librespot[16192]: time="2024-10-07T13:14:15+08:00" level=debug msg="zeroconf server listening on port 40329" Oct 07 13:14:16 volumio go-librespot[16192]: time="2024-10-07T13:14:16+08:00" level=debug msg="obtained new client token: AAA+AR+7bs5Ihy/L2qNDckVLgQ9/IxghHV7P31igjZjWsrF80f0MuRfMq4ncMmIN2afUNNznxPSVqERfvesvgkX8ZiR5PL0/IYigampChJA8uvqTn8fgJuKkxOpYqER666NAlTADqy/Vlobyy/ozyucRGvlS5ZgQhb/mQ+OHYrFh/BdU0dRPcNy+qN9r0U0WBfmjwGIB7houn2wq5GMDEkEB18kB80cfdorVVq9uWaPUBKkF7oAlQg9Q" Oct 07 13:14:16 volumio go-librespot[16192]: time="2024-10-07T13:14:16+08:00" level=debug msg="completed keyexchange" Oct 07 13:14:17 volumio go-librespot[16192]: time="2024-10-07T13:14:17+08:00" level=debug msg="completed challenge" Oct 07 13:14:17 volumio go-librespot[16192]: time="2024-10-07T13:14:17+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 07 13:14:17 volumio volumio[928]: info: Connection to go-librespot Websocket closed Oct 07 13:14:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 07 13:14:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 07 13:14:18 volumio volumio[928]: info: Getting Spotify volume Oct 07 13:14:18 volumio volumio[928]: (node:928) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 07 13:14:18 volumio volumio[928]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Oct 07 13:14:18 volumio volumio[928]: (node:928) 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: 6987) Oct 07 13:14:18 volumio volumio[928]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Oct 07 13:14:18 volumio volumio[928]: info: CoreCommandRouter::volumioGetState Oct 07 13:14:18 volumio volumio[928]: info: CorePlayQueue::getTrack 7 Oct 07 13:14:20 volumio volumio[928]: info: Initializing connection to go-librespot Websocket Oct 07 13:14:20 volumio volumio[928]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 07 13:14:20 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 07 13:14:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13997. Oct 07 13:14:20 volumio systemd[1]: Stopped go-librespot Daemon. Oct 07 13:14:20 volumio systemd[1]: Started go-librespot Daemon. Oct 07 13:14:20 volumio go-librespot[16200]: Librespot-go daemon starting... Oct 07 13:14:20 volumio go-librespot[16200]: time="2024-10-07T13:14:20+08:00" level=info msg="generated new device id: 45a2fb31a441eaa07f184f68b083f5960c0ec83e" Oct 07 13:14:20 volumio go-librespot[16200]: time="2024-10-07T13:14:20+08:00" level=debug msg="stored credentials not found" Oct 07 13:14:21 volumio go-librespot[16200]: time="2024-10-07T13:14:21+08:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 07 13:14:21 volumio go-librespot[16200]: time="2024-10-07T13:14:21+08:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 07 13:14:21 volumio go-librespot[16200]: time="2024-10-07T13:14:21+08:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 07 13:14:21 volumio go-librespot[16200]: time="2024-10-07T13:14:21+08:00" level=debug msg="zeroconf server listening on port 39459" Oct 07 13:14:21 volumio go-librespot[16200]: time="2024-10-07T13:14:21+08:00" level=debug msg="obtained new client token: AABxAuREDziatw9bgRtK+m1z+qla2jKMkH50sHY3muzRpirAGa2/+6bVFw4YCiIEPOHnnW8Hw36KsUusb9bgXPLoxwNUHs10iLvIURrqsqLXgj/H8oLHBPi9L58V6v7jT32JIMKU4u4FDrBmgD1A+/rde/h46oemNNHl5f7sZZQLYzn07U1jbWNmqK9p+JmIDS048eNcx7kg9Qwb8xqW4Ymvq2seQxd0NgbQbww7FMyYW2neEBjZqn1iEFA=" Oct 07 13:14:22 volumio go-librespot[16200]: time="2024-10-07T13:14:22+08:00" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed dialing accesspoint: dial tcp 104.154.127.247:4070: connect: connection refused" Oct 07 13:14:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 07 13:14:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 07 13:14:23 volumio volumio[928]: info: Initializing connection to go-librespot Websocket Oct 07 13:14:23 volumio volumio[928]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 07 13:14:25 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 07 13:14:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13998. Oct 07 13:14:25 volumio systemd[1]: Stopped go-librespot Daemon. Oct 07 13:14:25 volumio systemd[1]: Started go-librespot Daemon. Oct 07 13:14:25 volumio go-librespot[16208]: Librespot-go daemon starting... Oct 07 13:14:25 volumio go-librespot[16208]: time="2024-10-07T13:14:25+08:00" level=info msg="generated new device id: d6873b7a10d1c5488a1fb33f56f87630f931279f" Oct 07 13:14:25 volumio go-librespot[16208]: time="2024-10-07T13:14:25+08:00" level=debug msg="stored credentials not found" Oct 07 13:14:25 volumio go-librespot[16208]: time="2024-10-07T13:14:25+08:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 07 13:14:25 volumio go-librespot[16208]: time="2024-10-07T13:14:25+08:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 07 13:14:25 volumio go-librespot[16208]: time="2024-10-07T13:14:25+08:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 07 13:14:25 volumio go-librespot[16208]: time="2024-10-07T13:14:25+08:00" level=debug msg="zeroconf server listening on port 44887" Oct 07 13:14:26 volumio go-librespot[16208]: time="2024-10-07T13:14:26+08:00" level=debug msg="obtained new client token: AAAc/Z6TkLyOHmMTxVVjoNtDZ/wu6srIPCKOsG8kYNln7nCVOJr47Nhfww8EBL1CjdptIOvbFD9X41y7yMvEqo1A4rmI51JY9PCGdgZP5YdfZO8vsG616wKnw3VceJewFcz5XAvd52/IRuHRXf3Tz7cXZ3Fdn815fm8jlxgqusue1/BkuJqr+BvZWidFYHYbPPEXKlRfEt50FsEc3G8SZ2EB9BRa6XYuIBnJ2nCYqFix2i5D34uXgzO4v+k=" Oct 07 13:14:26 volumio volumio[928]: info: Initializing connection to go-librespot Websocket Oct 07 13:14:26 volumio go-librespot[16208]: time="2024-10-07T13:14:26+08:00" level=debug msg="new websocket client" Oct 07 13:14:26 volumio volumio[928]: info: Connection to go-librespot Websocket established Oct 07 13:14:26 volumio go-librespot[16208]: time="2024-10-07T13:14:26+08:00" level=debug msg="completed keyexchange" Oct 07 13:14:27 volumio go-librespot[16208]: time="2024-10-07T13:14:27+08:00" level=debug msg="completed challenge" Oct 07 13:14:27 volumio go-librespot[16208]: time="2024-10-07T13:14:27+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 07 13:14:27 volumio volumio[928]: info: Connection to go-librespot Websocket closed Oct 07 13:14:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 07 13:14:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 07 13:14:29 volumio volumio[928]: info: Getting Spotify volume Oct 07 13:14:29 volumio volumio[928]: (node:928) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 07 13:14:29 volumio volumio[928]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Oct 07 13:14:29 volumio volumio[928]: (node:928) 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: 6988) Oct 07 13:14:29 volumio volumio[928]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Oct 07 13:14:29 volumio volumio[928]: info: CoreCommandRouter::volumioGetState Oct 07 13:14:29 volumio volumio[928]: info: CorePlayQueue::getTrack 7 Oct 07 13:14:30 volumio volumio[928]: info: Initializing connection to go-librespot Websocket Oct 07 13:14:30 volumio volumio[928]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 07 13:14:30 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 07 13:14:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13999. Oct 07 13:14:30 volumio systemd[1]: Stopped go-librespot Daemon. Oct 07 13:14:30 volumio systemd[1]: Started go-librespot Daemon. Oct 07 13:14:30 volumio go-librespot[16217]: Librespot-go daemon starting... Oct 07 13:14:31 volumio go-librespot[16217]: time="2024-10-07T13:14:31+08:00" level=info msg="generated new device id: f7e1f4bb50e7eb9fb6bfec8df72ef47141de80f8" Oct 07 13:14:31 volumio go-librespot[16217]: time="2024-10-07T13:14:31+08:00" level=debug msg="stored credentials not found" Oct 07 13:14:31 volumio go-librespot[16217]: time="2024-10-07T13:14:31+08:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 07 13:14:31 volumio go-librespot[16217]: time="2024-10-07T13:14:31+08:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 07 13:14:31 volumio go-librespot[16217]: time="2024-10-07T13:14:31+08:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 07 13:14:31 volumio go-librespot[16217]: time="2024-10-07T13:14:31+08:00" level=debug msg="zeroconf server listening on port 46159" Oct 07 13:14:32 volumio go-librespot[16217]: time="2024-10-07T13:14:32+08:00" level=debug msg="obtained new client token: AABhiuGVadHJMyfYib9K0/zexP8VvXRBs84HArZBi+oL166jmB41rJKWmqn6GPNuk8Nv1ONHuPvP44JJDHxes+UQjLsXE2l9MFjrledhGaQwI7ZS7bnWDxILlg28zaAwSIhkG9jr51/sxduN/Wz6wSc5uEoNB4R+27RksnBCGP58MIJpFfKZ09EfxQ3T7yHzT9nw9vTJ37OpLnXuJ0aU1Bsllds9LWBFygcUscVmyjCcTDEhDE0lEdmq" Oct 07 13:14:32 volumio go-librespot[16217]: time="2024-10-07T13:14:32+08:00" level=debug msg="completed keyexchange" Oct 07 13:14:33 volumio go-librespot[16217]: time="2024-10-07T13:14:33+08:00" level=debug msg="completed challenge" Oct 07 13:14:33 volumio go-librespot[16217]: time="2024-10-07T13:14:33+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 07 13:14:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 07 13:14:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 07 13:14:33 volumio volumio[928]: info: Initializing connection to go-librespot Websocket Oct 07 13:14:33 volumio volumio[928]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 07 13:14:36 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 07 13:14:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14000. Oct 07 13:14:36 volumio systemd[1]: Stopped go-librespot Daemon. Oct 07 13:14:36 volumio systemd[1]: Started go-librespot Daemon. Oct 07 13:14:36 volumio go-librespot[16227]: Librespot-go daemon starting... Oct 07 13:14:36 volumio go-librespot[16227]: time="2024-10-07T13:14:36+08:00" level=info msg="generated new device id: 38819240fb6af9b09c314412c08a5447a40b408a" Oct 07 13:14:36 volumio go-librespot[16227]: time="2024-10-07T13:14:36+08:00" level=debug msg="stored credentials not found" Oct 07 13:14:36 volumio volumio[928]: info: Initializing connection to go-librespot Websocket Oct 07 13:14:36 volumio go-librespot[16227]: time="2024-10-07T13:14:36+08:00" level=debug msg="new websocket client" Oct 07 13:14:36 volumio volumio[928]: info: Connection to go-librespot Websocket established Oct 07 13:14:37 volumio go-librespot[16227]: time="2024-10-07T13:14:37+08:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 07 13:14:37 volumio go-librespot[16227]: time="2024-10-07T13:14:37+08:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 07 13:14:37 volumio go-librespot[16227]: time="2024-10-07T13:14:37+08:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 07 13:14:37 volumio go-librespot[16227]: time="2024-10-07T13:14:37+08:00" level=debug msg="zeroconf server listening on port 38659" Oct 07 13:14:37 volumio go-librespot[16227]: time="2024-10-07T13:14:37+08:00" level=debug msg="obtained new client token: AADwQPOpFMOfSELJdfFKYkVALFpVTe9X6t9fqJGOGRGMdG/OYNAhpizrGUg12Yb/9Swq/+OXwnkrR0xWAmdxrIUOfl4Jjvaj+8HmspbE0B8Ud7YASOrjMuHYEnl9l8nxoq5jjwWgHGN188w9pacRNhOMq9fRWMg9CRklAA8/7gThcefuJrSpSqmbDsBIP8VfTR/Qb6w1d5CYILjDf0IkCSrncEr00e0u/RKsxFAlPtJ9qmfIVtXh/RWzO0k=" Oct 07 13:14:38 volumio go-librespot[16227]: time="2024-10-07T13:14:38+08:00" level=debug msg="completed keyexchange" Oct 07 13:14:38 volumio go-librespot[16227]: time="2024-10-07T13:14:38+08:00" level=debug msg="completed challenge" Oct 07 13:14:39 volumio go-librespot[16227]: time="2024-10-07T13:14:39+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 07 13:14:39 volumio volumio[928]: info: Connection to go-librespot Websocket closed Oct 07 13:14:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 07 13:14:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 07 13:14:39 volumio volumio[928]: info: Getting Spotify volume Oct 07 13:14:39 volumio volumio[928]: (node:928) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 07 13:14:39 volumio volumio[928]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Oct 07 13:14:39 volumio volumio[928]: (node:928) 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: 6989) Oct 07 13:14:39 volumio volumio[928]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Oct 07 13:14:39 volumio volumio[928]: info: CoreCommandRouter::volumioGetState Oct 07 13:14:39 volumio volumio[928]: info: CorePlayQueue::getTrack 7 Oct 07 13:14:41 volumio sudo[16236]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 07 13:14:41 volumio sudo[16236]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 07 13:14:41 volumio sudo[16236]: pam_unix(sudo:session): session closed for user root Oct 07 13:14:41 volumio sudo[16239]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 07 13:14:41 volumio sudo[16239]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 07 13:14:41 volumio sudo[16239]: pam_unix(sudo:session): session closed for user root Oct 07 13:14:41 volumio volumio[928]: verbose: New Socket.io Connection to 192.168.31.88 from 192.168.31.23 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_6_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/17.6 Mobile/15E148 Safari/604.1 Engine version: 3 Transport: polling Total Clients: 5 Oct 07 13:14:42 volumio volumio[928]: info: CoreCommandRouter::volumioGetVisibleSources Oct 07 13:14:42 volumio volumio[928]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 07 13:14:42 volumio volumio[928]: info: CoreCommandRouter::volumioGetState Oct 07 13:14:42 volumio volumio[928]: info: CorePlayQueue::getTrack 7 Oct 07 13:14:42 volumio volumio[928]: info: CoreCommandRouter::volumioGetQueue Oct 07 13:14:42 volumio volumio[928]: info: CoreStateMachine::getQueue Oct 07 13:14:42 volumio volumio[928]: info: CorePlayQueue::getQueue Oct 07 13:14:42 volumio volumio[928]: info: Listing playlists Oct 07 13:14:42 volumio volumio[928]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 07 13:14:42 volumio volumio[928]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 07 13:14:42 volumio volumio[928]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 07 13:14:42 volumio volumio[928]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 07 13:14:42 volumio volumio[928]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 07 13:14:42 volumio volumio[928]: info: Initializing connection to go-librespot Websocket Oct 07 13:14:42 volumio volumio[928]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 07 13:14:42 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 07 13:14:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14001. Oct 07 13:14:42 volumio systemd[1]: Stopped go-librespot Daemon. Oct 07 13:14:42 volumio systemd[1]: Started go-librespot Daemon. Oct 07 13:14:42 volumio go-librespot[16241]: Librespot-go daemon starting... Oct 07 13:14:42 volumio go-librespot[16241]: time="2024-10-07T13:14:42+08:00" level=info msg="generated new device id: c0dd14891fff4168e0a3a05182d1e1ab88425a2b" Oct 07 13:14:42 volumio go-librespot[16241]: time="2024-10-07T13:14:42+08:00" level=debug msg="stored credentials not found" Oct 07 13:14:42 volumio go-librespot[16241]: time="2024-10-07T13:14:42+08:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 07 13:14:42 volumio go-librespot[16241]: time="2024-10-07T13:14:42+08:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 07 13:14:42 volumio go-librespot[16241]: time="2024-10-07T13:14:42+08:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 07 13:14:43 volumio go-librespot[16241]: time="2024-10-07T13:14:43+08:00" level=debug msg="zeroconf server listening on port 37479" Oct 07 13:14:43 volumio go-librespot[16241]: time="2024-10-07T13:14:43+08:00" level=debug msg="obtained new client token: AABqJ7uUUhVI2KM6/2cJD67NcFQqlJCjWA16i8JEoEvdYgGLjjcJIX4X1W4xEKeXidSGW6HQtiFkbPXokgiIgnccWBxSKIg1upk2PxiOAtQWaLWop6SmkwBtejfGQ3vsCww71u3mQi8pVZMSPzVnMKNvRqaLCS3bdV82GY2k1NoUyOQil01ndx2d02f3TOOupWFh6NFUsXvV3vEI63rD/vATXnUKBu68HdiH15A9BPzojGD6JRe5/7eGdOA=" Oct 07 13:14:43 volumio go-librespot[16241]: time="2024-10-07T13:14:43+08:00" level=debug msg="completed keyexchange" Oct 07 13:14:44 volumio go-librespot[16241]: time="2024-10-07T13:14:44+08:00" level=debug msg="completed challenge" Oct 07 13:14:45 volumio volumio[928]: info: Initializing connection to go-librespot Websocket Oct 07 13:14:45 volumio go-librespot[16241]: time="2024-10-07T13:14:45+08:00" level=debug msg="new websocket client" Oct 07 13:14:45 volumio volumio[928]: info: Connection to go-librespot Websocket established Oct 07 13:14:45 volumio go-librespot[16241]: time="2024-10-07T13:14:45+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 07 13:14:45 volumio volumio[928]: info: Connection to go-librespot Websocket closed Oct 07 13:14:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 07 13:14:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 07 13:14:48 volumio volumio[928]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Oct 07 13:14:48 volumio volumio[928]: info: CURURI: albums:// Oct 07 13:14:48 volumio volumio[928]: info: listAlbums - loading Albums from cache Oct 07 13:14:48 volumio volumio[928]: info: Getting Spotify volume Oct 07 13:14:48 volumio volumio[928]: (node:928) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 07 13:14:48 volumio volumio[928]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Oct 07 13:14:48 volumio volumio[928]: (node:928) 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: 6990) Oct 07 13:14:48 volumio volumio[928]: info: Preload queue cleared Oct 07 13:14:48 volumio volumio[928]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Oct 07 13:14:48 volumio volumio[928]: info: CoreCommandRouter::volumioGetState Oct 07 13:14:48 volumio volumio[928]: info: CorePlayQueue::getTrack 7 Oct 07 13:14:48 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 07 13:14:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14002. Oct 07 13:14:48 volumio systemd[1]: Stopped go-librespot Daemon. Oct 07 13:14:48 volumio systemd[1]: Started go-librespot Daemon. Oct 07 13:14:48 volumio go-librespot[16250]: Librespot-go daemon starting... Oct 07 13:14:48 volumio go-librespot[16250]: time="2024-10-07T13:14:48+08:00" level=info msg="generated new device id: ea44fea773bd215cbb4d7834a8edec63aef7fe77" Oct 07 13:14:48 volumio go-librespot[16250]: time="2024-10-07T13:14:48+08:00" level=debug msg="stored credentials not found" Oct 07 13:14:49 volumio go-librespot[16250]: time="2024-10-07T13:14:49+08:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 07 13:14:49 volumio go-librespot[16250]: time="2024-10-07T13:14:49+08:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 07 13:14:49 volumio go-librespot[16250]: time="2024-10-07T13:14:49+08:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 07 13:14:49 volumio go-librespot[16250]: time="2024-10-07T13:14:49+08:00" level=debug msg="zeroconf server listening on port 41911" Oct 07 13:14:49 volumio go-librespot[16250]: time="2024-10-07T13:14:49+08:00" level=debug msg="obtained new client token: AACvcjHeC3G8iVE+cg27xLAD4/4wncdDDPHfOryLkfegiWv2WO/1y4E9/JeyxabwTywUmWGzb3nqo0fEJjKu0qCFZSH7eV2vkXNuBx3Q5ZS9UlftmEfkX0j43lN1RRl6Kt23sMXCeJurvt+Xw/Ag/GwcktAUElkiFUQfSdap3D7jbgAC2k5F0v2/PsDla7hN5tXeJ0iEqUupVUS+S8Jaf3/THrrz/aMN35LiQSEbe4GcFh5yTmKlnyN4u0g=" Oct 07 13:14:50 volumio volumio[928]: info: Initializing connection to go-librespot Websocket Oct 07 13:14:50 volumio go-librespot[16250]: time="2024-10-07T13:14:50+08:00" level=debug msg="completed keyexchange" Oct 07 13:14:50 volumio volumio[928]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/*/61b36356-322d-4ef9-9d22-7a93f2e0f211.jpg' Oct 07 13:14:50 volumio go-librespot[16250]: time="2024-10-07T13:14:50+08:00" level=debug msg="completed challenge" Oct 07 13:14:51 volumio go-librespot[16250]: time="2024-10-07T13:14:51+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 07 13:14:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 07 13:14:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 07 13:14:52 volumio volumio[928]: info: Error connecting to go-librespot Websocket: Error: socket hang up Oct 07 13:14:53 volumio volumio[928]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Oct 07 13:14:53 volumio volumio[928]: info: CURURI: albums://%E9%99%88%E7%99%BE%E5%BC%BA/%E7%99%BE%E5%90%AC%E4%B8%8D%E5%8E%8C%E7%B2%A4%E8%AF%AD Oct 07 13:14:53 volumio volumio[928]: info: Preload queue cleared Oct 07 13:14:53 volumio volumio[928]: info: Preloading song: music-library/NAS/NAS/【1】百听不厌粤语（200首）/0034.陈百强 - 疾风.mp3 Oct 07 13:14:53 volumio volumio[928]: info: Preloading song: music-library/NAS/NAS/【1】百听不厌粤语（200首）/0035.陈百强 - 至爱.mp3 Oct 07 13:14:53 volumio volumio[928]: info: Preloading song: music-library/NAS/NAS/【1】百听不厌粤语（200首）/0079.陈百强 - 只因爱你.mp3 Oct 07 13:14:53 volumio volumio[928]: info: Preloading song: music-library/NAS/NAS/【1】百听不厌粤语（200首）/0105.陈百强 - 寂寞的感觉.mp3 Oct 07 13:14:53 volumio volumio[928]: info: Preloading song: music-library/NAS/NAS/【1】百听不厌粤语（200首）/0107.陈百强 - 一生不可自决.mp3 Oct 07 13:14:53 volumio volumio[928]: info: Preloading song: music-library/NAS/NAS/【1】百听不厌粤语（200首）/0120.陈百强 - 一生何求.mp3 Oct 07 13:14:53 volumio volumio[928]: info: Preloading song: music-library/NAS/NAS/【1】百听不厌粤语（200首）/0156.陈百强 - 有了你.mp3 Oct 07 13:14:53 volumio volumio[928]: info: Preloading song: music-library/NAS/NAS/【1】百听不厌粤语（200首）/0189.陈百强 - 当我想起你.mp3 Oct 07 13:14:53 volumio volumio[928]: info: Preloading song: music-library/NAS/NAS/【1】百听不厌粤语（200首）/0196.陈百强 - 别话.mp3 Oct 07 13:14:53 volumio volumio[928]: info: Exploding uri music-library/NAS/NAS/【1】百听不厌粤语（200首）/0034.陈百强 - 疾风.mp3 in service mpd Oct 07 13:14:53 volumio volumio[928]: info: ALBUMART /albumart?cacheid=361&web=%E9%99%88%E7%99%BE%E5%BC%BA/%E7%99%BE%E5%90%AC%E4%B8%8D%E5%8E%8C%E7%B2%A4%E8%AF%AD/extralarge&path=%2Fmnt%2FNAS%2FNAS%2F%E3%80%901%E3%80%91%E7%99%BE%E5%90%AC%E4%B8%8D%E5%8E%8C%E7%B2%A4%E8%AF%AD%EF%BC%88200%E9%A6%96%EF%BC%89%2F0034.%E9%99%88%E7%99%BE%E5%BC%BA%20-%20%E7%96%BE%E9%A3%8E.mp3&metadata=false Oct 07 13:14:53 volumio volumio[928]: info: URI /mnt/NAS/NAS/【1】百听不厌粤语（200首）/0034.陈百强 - 疾风.mp3 Oct 07 13:14:53 volumio volumio[928]: info: Exploding uri music-library/NAS/NAS/【1】百听不厌粤语（200首）/0035.陈百强 - 至爱.mp3 in service mpd Oct 07 13:14:53 volumio volumio[928]: info: Exploding uri music-library/NAS/NAS/【1】百听不厌粤语（200首）/0079.陈百强 - 只因爱你.mp3 in service mpd Oct 07 13:14:53 volumio volumio[928]: info: Exploding uri music-library/NAS/NAS/【1】百听不厌粤语（200首）/0105.陈百强 - 寂寞的感觉.mp3 in service mpd Oct 07 13:14:53 volumio volumio[928]: info: Exploding uri music-library/NAS/NAS/【1】百听不厌粤语（200首）/0107.陈百强 - 一生不可自决.mp3 in service mpd Oct 07 13:14:53 volumio volumio[928]: info: Exploding uri music-library/NAS/NAS/【1】百听不厌粤语（200首）/0120.陈百强 - 一生何求.mp3 in service mpd Oct 07 13:14:53 volumio volumio[928]: info: Exploding uri music-library/NAS/NAS/【1】百听不厌粤语（200首）/0156.陈百强 - 有了你.mp3 in service mpd Oct 07 13:14:53 volumio volumio[928]: info: ALBUMART /albumart?cacheid=361&web=%E9%99%88%E7%99%BE%E5%BC%BA/%E7%99%BE%E5%90%AC%E4%B8%8D%E5%8E%8C%E7%B2%A4%E8%AF%AD/extralarge&path=%2Fmnt%2FNAS%2FNAS%2F%E3%80%901%E3%80%91%E7%99%BE%E5%90%AC%E4%B8%8D%E5%8E%8C%E7%B2%A4%E8%AF%AD%EF%BC%88200%E9%A6%96%EF%BC%89%2F0035.%E9%99%88%E7%99%BE%E5%BC%BA%20-%20%E8%87%B3%E7%88%B1.mp3&metadata=false Oct 07 13:14:53 volumio volumio[928]: info: URI /mnt/NAS/NAS/【1】百听不厌粤语（200首）/0035.陈百强 - 至爱.mp3 Oct 07 13:14:53 volumio volumio[928]: info: ALBUMART /albumart?cacheid=361&web=%E9%99%88%E7%99%BE%E5%BC%BA/%E7%99%BE%E5%90%AC%E4%B8%8D%E5%8E%8C%E7%B2%A4%E8%AF%AD/extralarge&path=%2Fmnt%2FNAS%2FNAS%2F%E3%80%901%E3%80%91%E7%99%BE%E5%90%AC%E4%B8%8D%E5%8E%8C%E7%B2%A4%E8%AF%AD%EF%BC%88200%E9%A6%96%EF%BC%89%2F0079.%E9%99%88%E7%99%BE%E5%BC%BA%20-%20%E5%8F%AA%E5%9B%A0%E7%88%B1%E4%BD%A0.mp3&metadata=false Oct 07 13:14:53 volumio volumio[928]: info: URI /mnt/NAS/NAS/【1】百听不厌粤语（200首）/0079.陈百强 - 只因爱你.mp3 Oct 07 13:14:53 volumio volumio[928]: info: ALBUMART /albumart?cacheid=361&web=%E9%99%88%E7%99%BE%E5%BC%BA/%E7%99%BE%E5%90%AC%E4%B8%8D%E5%8E%8C%E7%B2%A4%E8%AF%AD/extralarge&path=%2Fmnt%2FNAS%2FNAS%2F%E3%80%901%E3%80%91%E7%99%BE%E5%90%AC%E4%B8%8D%E5%8E%8C%E7%B2%A4%E8%AF%AD%EF%BC%88200%E9%A6%96%EF%BC%89%2F0105.%E9%99%88%E7%99%BE%E5%BC%BA%20-%20%E5%AF%82%E5%AF%9E%E7%9A%84%E6%84%9F%E8%A7%89.mp3&metadata=false Oct 07 13:14:53 volumio volumio[928]: info: URI /mnt/NAS/NAS/【1】百听不厌粤语（200首）/0105.陈百强 - 寂寞的感觉.mp3 Oct 07 13:14:53 volumio volumio[928]: info: ALBUMART /albumart?cacheid=361&web=%E9%99%88%E7%99%BE%E5%BC%BA/%E7%99%BE%E5%90%AC%E4%B8%8D%E5%8E%8C%E7%B2%A4%E8%AF%AD/extralarge&path=%2Fmnt%2FNAS%2FNAS%2F%E3%80%901%E3%80%91%E7%99%BE%E5%90%AC%E4%B8%8D%E5%8E%8C%E7%B2%A4%E8%AF%AD%EF%BC%88200%E9%A6%96%EF%BC%89%2F0107.%E9%99%88%E7%99%BE%E5%BC%BA%20-%20%E4%B8%80%E7%94%9F%E4%B8%8D%E5%8F%AF%E8%87%AA%E5%86%B3.mp3&metadata=false Oct 07 13:14:53 volumio volumio[928]: info: URI /mnt/NAS/NAS/【1】百听不厌粤语（200首）/0107.陈百强 - 一生不可自决.mp3 Oct 07 13:14:53 volumio volumio[928]: info: ALBUMART /albumart?cacheid=361&web=%E9%99%88%E7%99%BE%E5%BC%BA/%E7%99%BE%E5%90%AC%E4%B8%8D%E5%8E%8C%E7%B2%A4%E8%AF%AD/extralarge&path=%2Fmnt%2FNAS%2FNAS%2F%E3%80%901%E3%80%91%E7%99%BE%E5%90%AC%E4%B8%8D%E5%8E%8C%E7%B2%A4%E8%AF%AD%EF%BC%88200%E9%A6%96%EF%BC%89%2F0120.%E9%99%88%E7%99%BE%E5%BC%BA%20-%20%E4%B8%80%E7%94%9F%E4%BD%95%E6%B1%82.mp3&metadata=false Oct 07 13:14:53 volumio volumio[928]: info: URI /mnt/NAS/NAS/【1】百听不厌粤语（200首）/0120.陈百强 - 一生何求.mp3 Oct 07 13:14:53 volumio volumio[928]: info: ALBUMART /albumart?cacheid=361&web=%E9%99%88%E7%99%BE%E5%BC%BA/%E7%99%BE%E5%90%AC%E4%B8%8D%E5%8E%8C%E7%B2%A4%E8%AF%AD/extralarge&path=%2Fmnt%2FNAS%2FNAS%2F%E3%80%901%E3%80%91%E7%99%BE%E5%90%AC%E4%B8%8D%E5%8E%8C%E7%B2%A4%E8%AF%AD%EF%BC%88200%E9%A6%96%EF%BC%89%2F0156.%E9%99%88%E7%99%BE%E5%BC%BA%20-%20%E6%9C%89%E4%BA%86%E4%BD%A0.mp3&metadata=false Oct 07 13:14:53 volumio volumio[928]: info: URI /mnt/NAS/NAS/【1】百听不厌粤语（200首）/0156.陈百强 - 有了你.mp3 Oct 07 13:14:53 volumio volumio[928]: info: Exploding uri music-library/NAS/NAS/【1】百听不厌粤语（200首）/0189.陈百强 - 当我想起你.mp3 in service mpd Oct 07 13:14:53 volumio volumio[928]: info: Exploding uri music-library/NAS/NAS/【1】百听不厌粤语（200首）/0196.陈百强 - 别话.mp3 in service mpd Oct 07 13:14:53 volumio volumio[928]: info: ALBUMART /albumart?cacheid=361&web=%E9%99%88%E7%99%BE%E5%BC%BA/%E7%99%BE%E5%90%AC%E4%B8%8D%E5%8E%8C%E7%B2%A4%E8%AF%AD/extralarge&path=%2Fmnt%2FNAS%2FNAS%2F%E3%80%901%E3%80%91%E7%99%BE%E5%90%AC%E4%B8%8D%E5%8E%8C%E7%B2%A4%E8%AF%AD%EF%BC%88200%E9%A6%96%EF%BC%89%2F0189.%E9%99%88%E7%99%BE%E5%BC%BA%20-%20%E5%BD%93%E6%88%91%E6%83%B3%E8%B5%B7%E4%BD%A0.mp3&metadata=false Oct 07 13:14:53 volumio volumio[928]: info: URI /mnt/NAS/NAS/【1】百听不厌粤语（200首）/0189.陈百强 - 当我想起你.mp3 Oct 07 13:14:53 volumio volumio[928]: info: ALBUMART /albumart?cacheid=361&web=%E9%99%88%E7%99%BE%E5%BC%BA/%E7%99%BE%E5%90%AC%E4%B8%8D%E5%8E%8C%E7%B2%A4%E8%AF%AD/extralarge&path=%2Fmnt%2FNAS%2FNAS%2F%E3%80%901%E3%80%91%E7%99%BE%E5%90%AC%E4%B8%8D%E5%8E%8C%E7%B2%A4%E8%AF%AD%EF%BC%88200%E9%A6%96%EF%BC%89%2F0196.%E9%99%88%E7%99%BE%E5%BC%BA%20-%20%E5%88%AB%E8%AF%9D.mp3&metadata=false Oct 07 13:14:53 volumio volumio[928]: info: URI /mnt/NAS/NAS/【1】百听不厌粤语（200首）/0196.陈百强 - 别话.mp3 Oct 07 13:14:54 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 07 13:14:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14003. Oct 07 13:14:54 volumio systemd[1]: Stopped go-librespot Daemon. Oct 07 13:14:54 volumio systemd[1]: Started go-librespot Daemon. Oct 07 13:14:54 volumio go-librespot[16259]: Librespot-go daemon starting... Oct 07 13:14:54 volumio go-librespot[16259]: time="2024-10-07T13:14:54+08:00" level=info msg="generated new device id: 351d2d34090fc61bbcc2ea121ac915547ac46018" Oct 07 13:14:54 volumio go-librespot[16259]: time="2024-10-07T13:14:54+08:00" level=debug msg="stored credentials not found" Oct 07 13:14:55 volumio go-librespot[16259]: time="2024-10-07T13:14:55+08:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Oct 07 13:14:55 volumio go-librespot[16259]: time="2024-10-07T13:14:55+08:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Oct 07 13:14:55 volumio go-librespot[16259]: time="2024-10-07T13:14:55+08:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Oct 07 13:14:55 volumio go-librespot[16259]: time="2024-10-07T13:14:55+08:00" level=debug msg="zeroconf server listening on port 41103" Oct 07 13:14:55 volumio go-librespot[16259]: time="2024-10-07T13:14:55+08:00" level=debug msg="obtained new client token: AAD3FD5o6NDlMpKWpT5izquU4y/Yef01RdkoENGDGXYAVU/k/E48qZj4yODNt6JtRyTY7v+7IvnIUWr45k0n2UTLD0b9haFbYCaZ5VN9MQbZYJpA0hkWKdaOfG4t0j01OWc//llYq2feaY++Hp8BYAKl7zrjpoZ0TbdqbccczSQN48YqQRyv7bIuXozkIiTr9IX5ZN0g7pTa9hThbbEkjy58P7orldvo183OSDGg3IUba5ZcYZWRPdrJ/oc=" Oct 07 13:14:55 volumio volumio[928]: info: Initializing connection to go-librespot Websocket Oct 07 13:14:56 volumio go-librespot[16259]: time="2024-10-07T13:14:56+08:00" level=debug msg="completed keyexchange" Oct 07 13:14:56 volumio go-librespot[16259]: time="2024-10-07T13:14:56+08:00" level=debug msg="completed challenge" Oct 07 13:14:56 volumio go-librespot[16259]: time="2024-10-07T13:14:56+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 07 13:14:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 07 13:14:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 07 13:14:59 volumio volumio[928]: info: Error connecting to go-librespot Websocket: Error: socket hang up Oct 07 13:15:00 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 07 13:15:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14004. Oct 07 13:15:00 volumio systemd[1]: Stopped go-librespot Daemon. Oct 07 13:15:00 volumio systemd[1]: Started go-librespot Daemon. Oct 07 13:15:00 volumio go-librespot[16269]: Librespot-go daemon starting... Oct 07 13:15:00 volumio go-librespot[16269]: time="2024-10-07T13:15:00+08:00" level=info msg="generated new device id: 0ef16ec12e1f162e9e2940b68826da3b8ca8e946" Oct 07 13:15:00 volumio go-librespot[16269]: time="2024-10-07T13:15:00+08:00" level=debug msg="stored credentials not found" Oct 07 13:15:01 volumio go-librespot[16269]: time="2024-10-07T13:15:01+08:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 07 13:15:01 volumio go-librespot[16269]: time="2024-10-07T13:15:01+08:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 07 13:15:01 volumio go-librespot[16269]: time="2024-10-07T13:15:01+08:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 07 13:15:01 volumio go-librespot[16269]: time="2024-10-07T13:15:01+08:00" level=debug msg="zeroconf server listening on port 43897" Oct 07 13:15:01 volumio go-librespot[16269]: time="2024-10-07T13:15:01+08:00" level=debug msg="obtained new client token: AACyIplKnu2Qe1c1nQeQDt3gidu2shl5Wzf3iKDaVyGQCXDM5pUTLigRu5NnGFa4RblrIQMojk6n0lEuWmnS7a4qvtyazY2bgVkTGCgfL7/zOO7F/f52boEVYUXVsWI5/mc9Ozvw5ZVPDpd5OXfH+2kqKBTW1RQmaBgFPdh4mk7C+rn2v8TZY/CNp/8Wh9mW2ekpWv09cBnW4rcpYYMWYwS/5dhDXU8MYnvByoSlEw3Z5K8O+8s/qPtEUd0=" Oct 07 13:15:02 volumio go-librespot[16269]: time="2024-10-07T13:15:02+08:00" level=debug msg="completed keyexchange" Oct 07 13:15:02 volumio volumio[928]: info: Initializing connection to go-librespot Websocket Oct 07 13:15:02 volumio volumio[928]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 07 13:15:02 volumio volumio[928]: Error: socket hang up Oct 07 13:15:02 volumio volumio[928]: at connResetException (internal/errors.js:607:14) Oct 07 13:15:02 volumio volumio[928]: at TLSSocket.socketOnEnd (_http_client.js:493:23) Oct 07 13:15:02 volumio volumio[928]: at TLSSocket.emit (events.js:327:22) Oct 07 13:15:02 volumio volumio[928]: at endReadableNT (internal/streams/readable.js:1327:12) Oct 07 13:15:02 volumio volumio[928]: at processTicksAndRejections (internal/process/task_queues.js:80:21) { Oct 07 13:15:02 volumio volumio[928]: code: 'ECONNRESET' Oct 07 13:15:02 volumio volumio[928]: } Oct 07 13:15:02 volumio volumio[928]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 07 13:15:02 volumio go-librespot[16269]: time="2024-10-07T13:15:02+08:00" level=debug msg="completed challenge" Oct 07 13:15:02 volumio go-librespot[16269]: time="2024-10-07T13:15:02+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials" Oct 07 13:15:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 07 13:15:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 07 13:15:03 volumio sudo[16324]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-07 13:14 Oct 07 13:15:03 volumio sudo[16324]: 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="5fd3886148e72a9cecd88a772d1f6079fb64d11a" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8bb23b009e91ae4c7ecd678f193e7d3b281fca0c" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 22 Jul 2024 07:17:01 PM CEST" VOLUMIO_VERSION="3.742" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="2782e52360f70dfab079c82951ebbbb1"