-- Logs begin at Sat 2024-04-20 05:53:09 UTC, end at Sat 2024-04-20 08:34:25 UTC. -- Apr 20 08:33:00 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 20 08:33:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2300. Apr 20 08:33:00 volumio systemd[1]: Stopped go-librespot Daemon. Apr 20 08:33:00 volumio go-librespot[6878]: Librespot-go daemon starting... Apr 20 08:33:00 volumio systemd[1]: Started go-librespot Daemon. Apr 20 08:33:00 volumio go-librespot[6878]: time="2024-04-20T08:33:00Z" level=info msg="generated new device id: 4e864a895b9f59d067d436839340305bdd811401" Apr 20 08:33:00 volumio go-librespot[6878]: time="2024-04-20T08:33:00Z" level=debug msg="stored credentials found for vloo68" Apr 20 08:33:00 volumio go-librespot[6878]: time="2024-04-20T08:33:00Z" level=debug msg="obtained new client token: AABkkUVUMWo2ifqpnkzP+kH//zmzUxge3Re5AYn/yRAW2PR+ETqELwtSzpKBuLW3+mTJwafbe91G8v8/3Yl5gXuMYNhUV5wC6DuezHhPU6sr8TNgfETsz+VYQwTKk81jALgFgnaDTNFExtFCKnqfhsaRyJT3EMy2p5YnsN5jWyYZaDxZ8LwxsKUFlkb+9J5nG1QkYb7OSmklM75M7u9hbOOfyXZihFV2JZLZRYVDb10ugjGFvAJ6/2lWUkVmPic=" Apr 20 08:33:00 volumio go-librespot[6878]: time="2024-04-20T08:33:00Z" 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]" Apr 20 08:33:00 volumio go-librespot[6878]: time="2024-04-20T08:33:00Z" level=debug msg="completed keyexchange" Apr 20 08:33:01 volumio go-librespot[6878]: time="2024-04-20T08:33:01Z" level=debug msg="completed challenge" Apr 20 08:33:01 volumio go-librespot[6878]: time="2024-04-20T08:33:01Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 20 08:33:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 20 08:33:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 20 08:33:01 volumio volumio[949]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Apr 20 08:33:01 volumio volumio[949]: info: CURURI: music-library Apr 20 08:33:01 volumio volumio[949]: info: Preload queue cleared Apr 20 08:33:01 volumio volumio[949]: info: Initializing connection to go-librespot Websocket Apr 20 08:33:01 volumio volumio[949]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 20 08:33:02 volumio volumio[949]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Apr 20 08:33:02 volumio volumio[949]: info: CURURI: music-library/USB Apr 20 08:33:02 volumio volumio[949]: info: Preload queue cleared Apr 20 08:33:02 volumio volumio[949]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Apr 20 08:33:02 volumio volumio[949]: info: CURURI: music-library/USB/MUSICS2 Apr 20 08:33:02 volumio volumio[949]: info: Preload queue cleared Apr 20 08:33:04 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 20 08:33:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2301. Apr 20 08:33:04 volumio systemd[1]: Stopped go-librespot Daemon. Apr 20 08:33:04 volumio systemd[1]: Started go-librespot Daemon. Apr 20 08:33:04 volumio go-librespot[6899]: Librespot-go daemon starting... Apr 20 08:33:04 volumio go-librespot[6899]: time="2024-04-20T08:33:04Z" level=info msg="generated new device id: 37d0ad872ae12a58dd1561fcdb41339cd24b54e0" Apr 20 08:33:04 volumio go-librespot[6899]: time="2024-04-20T08:33:04Z" level=debug msg="stored credentials found for vloo68" Apr 20 08:33:04 volumio go-librespot[6899]: time="2024-04-20T08:33:04Z" level=debug msg="obtained new client token: AABzmGTPUrAV/eR28prtFQETSh9y2oABwTOR8of95WJ/dQPSLCk9l6xXmhXvPaj9B/FQhLTHQFIrcYNLI5HL1UHlB7hTtmKQZcfsSjJ79Q7EIGEmzMYfY9gB4QGQnhIj8lu3enLqmCRfo1TZYrOPuJ3FmBzBRCFy074SHiw/6G+hstyTfAqbiUec4KqWJeQUVMUGVtw8gwmeDd4oMc4nBa+SLFDUUf8vpJMKcZiSh8R4aYUJ5aHgeqFAFXJV12c=" Apr 20 08:33:04 volumio volumio[949]: info: Initializing connection to go-librespot Websocket Apr 20 08:33:04 volumio go-librespot[6899]: time="2024-04-20T08:33:04Z" 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]" Apr 20 08:33:04 volumio go-librespot[6899]: time="2024-04-20T08:33:04Z" level=debug msg="new websocket client" Apr 20 08:33:04 volumio volumio[949]: info: Connection to go-librespot Websocket established Apr 20 08:33:04 volumio go-librespot[6899]: time="2024-04-20T08:33:04Z" level=debug msg="completed keyexchange" Apr 20 08:33:05 volumio go-librespot[6899]: time="2024-04-20T08:33:05Z" level=debug msg="completed challenge" Apr 20 08:33:05 volumio go-librespot[6899]: time="2024-04-20T08:33:05Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 20 08:33:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 20 08:33:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 20 08:33:05 volumio volumio[949]: info: Connection to go-librespot Websocket closed Apr 20 08:33:06 volumio volumio[949]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Apr 20 08:33:06 volumio volumio[949]: info: CURURI: music-library/USB/MUSICS Apr 20 08:33:06 volumio volumio[949]: info: Preload queue cleared Apr 20 08:33:07 volumio volumio[949]: info: Getting Spotify volume Apr 20 08:33:07 volumio volumio[949]: (node:949) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 20 08:33:07 volumio volumio[949]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 20 08:33:07 volumio volumio[949]: (node:949) 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: 233) Apr 20 08:33:07 volumio volumio[949]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 Apr 20 08:33:08 volumio volumio[949]: info: CoreCommandRouter::volumioGetState Apr 20 08:33:08 volumio volumio[949]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Apr 20 08:33:08 volumio volumio[949]: info: Initializing connection to go-librespot Websocket Apr 20 08:33:08 volumio volumio[949]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 20 08:33:08 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 20 08:33:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2302. Apr 20 08:33:08 volumio systemd[1]: Stopped go-librespot Daemon. Apr 20 08:33:08 volumio systemd[1]: Started go-librespot Daemon. Apr 20 08:33:08 volumio go-librespot[6919]: Librespot-go daemon starting... Apr 20 08:33:08 volumio go-librespot[6919]: time="2024-04-20T08:33:08Z" level=info msg="generated new device id: 79caef010135d231f688df430840cc7721a659b3" Apr 20 08:33:08 volumio go-librespot[6919]: time="2024-04-20T08:33:08Z" level=debug msg="stored credentials found for vloo68" Apr 20 08:33:08 volumio go-librespot[6919]: time="2024-04-20T08:33:08Z" level=debug msg="obtained new client token: AAD4cAPn7DFR2JIbsPu5//RQGuFRWQwYHxpDAYHFZoTWVjfxvEoQwNJ6+Dqj/ZEYMfAjU/0oP3SOKMnXMm1J8gDycMcCbtaeKK2zQnDXMKj8GPTmu6vB329EFKrWAGfSU2+ummjZ6KMkoNzGPQpSFfSouvsDtu87QgJo8hsDAOHaIYtrszNylOtOVvllhd2DE26O0RNiACMw6d00i/M95r6zGB6LfR2FOjdKTIQAPsioEuVTTTvLYmCNIpd54Yw=" Apr 20 08:33:08 volumio go-librespot[6919]: time="2024-04-20T08:33:08Z" 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]" Apr 20 08:33:08 volumio go-librespot[6919]: time="2024-04-20T08:33:08Z" level=debug msg="completed keyexchange" Apr 20 08:33:09 volumio go-librespot[6919]: time="2024-04-20T08:33:09Z" level=debug msg="completed challenge" Apr 20 08:33:09 volumio go-librespot[6919]: time="2024-04-20T08:33:09Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 20 08:33:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 20 08:33:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 20 08:33:11 volumio volumio[949]: info: Initializing connection to go-librespot Websocket Apr 20 08:33:11 volumio volumio[949]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 20 08:33:12 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 20 08:33:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2303. Apr 20 08:33:12 volumio systemd[1]: Stopped go-librespot Daemon. Apr 20 08:33:12 volumio systemd[1]: Started go-librespot Daemon. Apr 20 08:33:12 volumio go-librespot[6935]: Librespot-go daemon starting... Apr 20 08:33:12 volumio go-librespot[6935]: time="2024-04-20T08:33:12Z" level=info msg="generated new device id: 6d2d5329233f9cec74de84815b9b8964ebb72002" Apr 20 08:33:12 volumio go-librespot[6935]: time="2024-04-20T08:33:12Z" level=debug msg="stored credentials found for vloo68" Apr 20 08:33:13 volumio go-librespot[6935]: time="2024-04-20T08:33:13Z" level=debug msg="obtained new client token: AAAngfk0gbLU3/k484WowyUaBn3PcJ5ov+GowS5VXsDINd8Fvrom9ZG0sc1xjNlLbzkCLAelK0VUQgnEqVFMOSv5erzh89VRlOWU9xLwb7O1/D3xelRwdeXuSIh9FfErMfoSB+V4ahczW4q3gqwe6ALzLmZpqTq/5EDNEb+dA2U24mXqNesh66PcKy3T3x3rqnyo8VFiWcdJ4RnL4bsZR1Hr9i7XYQi1D5sWDxXfS5LOMgXLa9urHIHdyigq" Apr 20 08:33:13 volumio go-librespot[6935]: time="2024-04-20T08:33:13Z" 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]" Apr 20 08:33:13 volumio go-librespot[6935]: time="2024-04-20T08:33:13Z" level=debug msg="completed keyexchange" Apr 20 08:33:13 volumio go-librespot[6935]: time="2024-04-20T08:33:13Z" level=debug msg="completed challenge" Apr 20 08:33:13 volumio go-librespot[6935]: time="2024-04-20T08:33:13Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 20 08:33:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 20 08:33:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 20 08:33:14 volumio volumio[949]: info: Initializing connection to go-librespot Websocket Apr 20 08:33:14 volumio volumio[949]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 20 08:33:16 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 20 08:33:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2304. Apr 20 08:33:16 volumio systemd[1]: Stopped go-librespot Daemon. Apr 20 08:33:17 volumio systemd[1]: Started go-librespot Daemon. Apr 20 08:33:17 volumio go-librespot[6990]: Librespot-go daemon starting... Apr 20 08:33:17 volumio go-librespot[6990]: time="2024-04-20T08:33:17Z" level=info msg="generated new device id: c51e17d2782da7e1e739a32c47a07d2df135df36" Apr 20 08:33:17 volumio go-librespot[6990]: time="2024-04-20T08:33:17Z" level=debug msg="stored credentials found for vloo68" Apr 20 08:33:17 volumio go-librespot[6990]: time="2024-04-20T08:33:17Z" level=debug msg="obtained new client token: AAALqXg0SmDkAerRxemasqO/Pibx6bWv5x2PT0Ux9U3K8993HTte3LoYnipuMbocw3AA2/dpiahfG8fLEfKHprOFNYw6TKvhCDmOHuEUy1KFx8BvJ+Afb4zHhFRvOOiQDZbkWkgBpJvtwYf8YKpdn5hEj6hwDniT2jfTMSfe25GLJpty7tzx3j780xGSG6KJKXyaXOWcJ4NKuk6S+XfHfKysb59qlm8D4x9hAUOa3vNo8o8z6tT//S0vC8G0" Apr 20 08:33:17 volumio go-librespot[6990]: time="2024-04-20T08:33:17Z" 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]" Apr 20 08:33:17 volumio go-librespot[6990]: time="2024-04-20T08:33:17Z" level=debug msg="completed keyexchange" Apr 20 08:33:17 volumio volumio[949]: info: Initializing connection to go-librespot Websocket Apr 20 08:33:17 volumio go-librespot[6990]: time="2024-04-20T08:33:17Z" level=debug msg="new websocket client" Apr 20 08:33:17 volumio volumio[949]: info: Connection to go-librespot Websocket established Apr 20 08:33:17 volumio go-librespot[6990]: time="2024-04-20T08:33:17Z" level=debug msg="completed challenge" Apr 20 08:33:17 volumio go-librespot[6990]: time="2024-04-20T08:33:17Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 20 08:33:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 20 08:33:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 20 08:33:17 volumio volumio[949]: info: Connection to go-librespot Websocket closed Apr 20 08:33:20 volumio volumio[949]: info: Getting Spotify volume Apr 20 08:33:20 volumio volumio[949]: (node:949) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 20 08:33:20 volumio volumio[949]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 20 08:33:20 volumio volumio[949]: (node:949) 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: 234) Apr 20 08:33:20 volumio volumio[949]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 Apr 20 08:33:20 volumio volumio[949]: info: CoreCommandRouter::volumioGetState Apr 20 08:33:20 volumio volumio[949]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Apr 20 08:33:20 volumio volumio[949]: info: Initializing connection to go-librespot Websocket Apr 20 08:33:20 volumio volumio[949]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 20 08:33:21 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 20 08:33:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2305. Apr 20 08:33:21 volumio systemd[1]: Stopped go-librespot Daemon. Apr 20 08:33:21 volumio systemd[1]: Started go-librespot Daemon. Apr 20 08:33:21 volumio go-librespot[7006]: Librespot-go daemon starting... Apr 20 08:33:21 volumio go-librespot[7006]: time="2024-04-20T08:33:21Z" level=info msg="generated new device id: a34a707afde6b839af7e43c8644badb85c35382b" Apr 20 08:33:21 volumio go-librespot[7006]: time="2024-04-20T08:33:21Z" level=debug msg="stored credentials found for vloo68" Apr 20 08:33:21 volumio go-librespot[7006]: time="2024-04-20T08:33:21Z" level=debug msg="obtained new client token: AACmE3swgRhqL6HJaDBFzcYDHy1rXX4dIQymmZt8FtDdcTlNJlPQp6r1WImQpQgGEHRN9JTih9/P7i2OTsfmbdXjXr4Zg890eOzkpGUCwT9H8jpQ39eAI49oOMq8kPb1rD7LzQzzkvTEm847Bv+t5b6Nl8lnWSXClLR/hjfK5LUoHUHsDuYguz4xunO0Xli6SC/ZOlgod3LRr3uiRyTbqVVYAbEJlNQcdslFriK1ksLuk4kpi1RaU8gWSggiWxc=" Apr 20 08:33:21 volumio go-librespot[7006]: time="2024-04-20T08:33:21Z" 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]" Apr 20 08:33:21 volumio go-librespot[7006]: time="2024-04-20T08:33:21Z" level=debug msg="completed keyexchange" Apr 20 08:33:22 volumio go-librespot[7006]: time="2024-04-20T08:33:22Z" level=debug msg="completed challenge" Apr 20 08:33:22 volumio go-librespot[7006]: time="2024-04-20T08:33:22Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 20 08:33:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 20 08:33:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 20 08:33:23 volumio volumio[949]: info: Initializing connection to go-librespot Websocket Apr 20 08:33:23 volumio volumio[949]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 20 08:33:25 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 20 08:33:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2306. Apr 20 08:33:25 volumio systemd[1]: Stopped go-librespot Daemon. Apr 20 08:33:25 volumio systemd[1]: Started go-librespot Daemon. Apr 20 08:33:25 volumio go-librespot[7023]: Librespot-go daemon starting... Apr 20 08:33:25 volumio go-librespot[7023]: time="2024-04-20T08:33:25Z" level=info msg="generated new device id: 791b803eb1d22508b3e3c8fddfc2b6a34ec30270" Apr 20 08:33:25 volumio go-librespot[7023]: time="2024-04-20T08:33:25Z" level=debug msg="stored credentials found for vloo68" Apr 20 08:33:25 volumio go-librespot[7023]: time="2024-04-20T08:33:25Z" level=debug msg="obtained new client token: AABKy7fQ4mGWlfbUcg1g9OnZW6uLxAj1lW6QEG7vSGTcjnqgVG6wL2ufuHb5ZQzq0x9nb2hON6vdlXCyFPh5y9ELpyebXV8b3ak5qNNA7nb/znSlxydAC9NoQJIA0nZlTObKJRDfvOB7LkYeq232EYET+ye3efCfESVgLX2mV5VssBOPghyvzzl+Ol0ua8o1XfZVOyDboIY9uwcuEhyck78Npc9igy8mL3bgsbGp3G0cHjD9POpRORD3AX4WkrU=" Apr 20 08:33:25 volumio go-librespot[7023]: time="2024-04-20T08:33:25Z" 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]" Apr 20 08:33:25 volumio go-librespot[7023]: time="2024-04-20T08:33:25Z" level=debug msg="completed keyexchange" Apr 20 08:33:26 volumio go-librespot[7023]: time="2024-04-20T08:33:26Z" level=debug msg="completed challenge" Apr 20 08:33:26 volumio go-librespot[7023]: time="2024-04-20T08:33:26Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 20 08:33:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 20 08:33:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 20 08:33:26 volumio volumio[949]: info: Initializing connection to go-librespot Websocket Apr 20 08:33:26 volumio volumio[949]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 20 08:33:29 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 20 08:33:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2307. Apr 20 08:33:29 volumio systemd[1]: Stopped go-librespot Daemon. Apr 20 08:33:29 volumio systemd[1]: Started go-librespot Daemon. Apr 20 08:33:29 volumio go-librespot[7039]: Librespot-go daemon starting... Apr 20 08:33:29 volumio go-librespot[7039]: time="2024-04-20T08:33:29Z" level=info msg="generated new device id: 21c9c66752d9f4af641fe8d139ed2d0258290c64" Apr 20 08:33:29 volumio go-librespot[7039]: time="2024-04-20T08:33:29Z" level=debug msg="stored credentials found for vloo68" Apr 20 08:33:29 volumio go-librespot[7039]: time="2024-04-20T08:33:29Z" level=debug msg="obtained new client token: AACAUnJWPvD2EWhb23wq4Biv9JO1Td+zUf1sO8azI+4p2T3dNgKtzv880WvT7U6FlSonDbb3Hd6yLbwLLChzpLUd/UjktBwak0EuIemgbjp9xS/Cnt0ADzr+ds+gXabLg1bqNCHCUJRGd/ZsybuXXSkDy7bHt1rhJ0kQGc1CN685gjRTNWUFf2w0HaV7G+6n6DwWOl5drk3zXXXKOhsCJbjUSOTOtEG0gW50de9UdKb6R7hooGwcAvHXoCWpec4=" Apr 20 08:33:29 volumio go-librespot[7039]: time="2024-04-20T08:33:29Z" 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]" Apr 20 08:33:29 volumio go-librespot[7039]: time="2024-04-20T08:33:29Z" level=debug msg="completed keyexchange" Apr 20 08:33:29 volumio volumio[949]: info: Initializing connection to go-librespot Websocket Apr 20 08:33:29 volumio go-librespot[7039]: time="2024-04-20T08:33:29Z" level=debug msg="new websocket client" Apr 20 08:33:29 volumio volumio[949]: info: Connection to go-librespot Websocket established Apr 20 08:33:30 volumio go-librespot[7039]: time="2024-04-20T08:33:30Z" level=debug msg="completed challenge" Apr 20 08:33:30 volumio go-librespot[7039]: time="2024-04-20T08:33:30Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 20 08:33:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 20 08:33:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 20 08:33:30 volumio volumio[949]: info: Connection to go-librespot Websocket closed Apr 20 08:33:32 volumio volumio[949]: info: Getting Spotify volume Apr 20 08:33:32 volumio volumio[949]: (node:949) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 20 08:33:32 volumio volumio[949]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 20 08:33:33 volumio volumio[949]: (node:949) 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: 235) Apr 20 08:33:33 volumio volumio[949]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 Apr 20 08:33:33 volumio volumio[949]: info: CoreCommandRouter::volumioGetState Apr 20 08:33:33 volumio volumio[949]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Apr 20 08:33:33 volumio volumio[949]: info: Initializing connection to go-librespot Websocket Apr 20 08:33:33 volumio volumio[949]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 20 08:33:33 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 20 08:33:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2308. Apr 20 08:33:33 volumio systemd[1]: Stopped go-librespot Daemon. Apr 20 08:33:33 volumio systemd[1]: Started go-librespot Daemon. Apr 20 08:33:33 volumio go-librespot[7055]: Librespot-go daemon starting... Apr 20 08:33:33 volumio go-librespot[7055]: time="2024-04-20T08:33:33Z" level=info msg="generated new device id: 110c8cb9cfb0b49f987069fa80f1f8dbe347c728" Apr 20 08:33:33 volumio go-librespot[7055]: time="2024-04-20T08:33:33Z" level=debug msg="stored credentials found for vloo68" Apr 20 08:33:33 volumio go-librespot[7055]: time="2024-04-20T08:33:33Z" level=debug msg="obtained new client token: AAC3k3MmWWOeeJ8xg40qVaB9lTGSETd077syYs9geZV02KMedFciyVcaxshbFp3WSekFa4mO8XZKEWn8k2YOHSAVde922rDpJKDaGKTppl0Q6gCcH/mWdN57hbWM43/mjSGpru/prC6cPly6oy6ejtY+2ZpBvjKj6mBDhd8jDvUfJbYEFu4DiWA2OzCXoWDtK1G9UEMHWKhpxbtw2nVv3PRHOC80vVKU6mq5HFDx4QhZYHW3gz4HyVdiMVoOfKM=" Apr 20 08:33:33 volumio go-librespot[7055]: time="2024-04-20T08:33:33Z" 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]" Apr 20 08:33:33 volumio go-librespot[7055]: time="2024-04-20T08:33:33Z" level=debug msg="completed keyexchange" Apr 20 08:33:34 volumio go-librespot[7055]: time="2024-04-20T08:33:34Z" level=debug msg="completed challenge" Apr 20 08:33:34 volumio go-librespot[7055]: time="2024-04-20T08:33:34Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 20 08:33:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 20 08:33:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 20 08:33:36 volumio volumio[949]: info: Initializing connection to go-librespot Websocket Apr 20 08:33:36 volumio volumio[949]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 20 08:33:37 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 20 08:33:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2309. Apr 20 08:33:37 volumio systemd[1]: Stopped go-librespot Daemon. Apr 20 08:33:37 volumio systemd[1]: Started go-librespot Daemon. Apr 20 08:33:37 volumio go-librespot[7072]: Librespot-go daemon starting... Apr 20 08:33:37 volumio go-librespot[7072]: time="2024-04-20T08:33:37Z" level=info msg="generated new device id: 1524bf70d993f58d31c48c5e933c08daacd7c98d" Apr 20 08:33:37 volumio go-librespot[7072]: time="2024-04-20T08:33:37Z" level=debug msg="stored credentials found for vloo68" Apr 20 08:33:37 volumio go-librespot[7072]: time="2024-04-20T08:33:37Z" level=debug msg="obtained new client token: AACOVL9j9cwM0+sZvxOk/4UUMEY6na4z3LaQMNQvAHtTE0yePcQI1zf7pbgLESPTBusN0j+6rX7ao13zy2eaAFdtAE5lg6XDNWvuPL+Q9f7XXdLqpjFoW1YEiWX12mgh0VvS4f8oNIpXRY9FvPY6QsMyGsmVyGp592YCB4w8T+3KEL2fuGjivGh4Ms90xJbZ6TUHhb/ea6XY285AVAqOKCEAZGdvJ406DV8gYnzSIQXUNMU3Hl1RhrNLNMHf4lw=" Apr 20 08:33:37 volumio go-librespot[7072]: time="2024-04-20T08:33:37Z" 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]" Apr 20 08:33:37 volumio go-librespot[7072]: time="2024-04-20T08:33:37Z" level=debug msg="completed keyexchange" Apr 20 08:33:38 volumio go-librespot[7072]: time="2024-04-20T08:33:38Z" level=debug msg="completed challenge" Apr 20 08:33:38 volumio go-librespot[7072]: time="2024-04-20T08:33:38Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 20 08:33:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 20 08:33:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 20 08:33:39 volumio volumio[949]: info: Initializing connection to go-librespot Websocket Apr 20 08:33:39 volumio volumio[949]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 20 08:33:41 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 20 08:33:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2310. Apr 20 08:33:41 volumio systemd[1]: Stopped go-librespot Daemon. Apr 20 08:33:41 volumio systemd[1]: Started go-librespot Daemon. Apr 20 08:33:41 volumio go-librespot[7089]: Librespot-go daemon starting... Apr 20 08:33:41 volumio go-librespot[7089]: time="2024-04-20T08:33:41Z" level=info msg="generated new device id: e40a5db08da480ab914dbd47d486c33e86d986bb" Apr 20 08:33:41 volumio go-librespot[7089]: time="2024-04-20T08:33:41Z" level=debug msg="stored credentials found for vloo68" Apr 20 08:33:41 volumio go-librespot[7089]: time="2024-04-20T08:33:41Z" level=debug msg="obtained new client token: AACOD6UZYM1IlrF+HB/741I7pyYNANB9obQ3el+8hm71yVXdkQQ2FLnTf6T8c3v60SFh0ejj0GJerwLUp0kRRc3X5yqdWHDJSE+a3Yg7xBO5eYLxbrhVd9vH1Y5vTJlKFWTPrRu0GdcGFwDX7o/fh8Y+MXdp8Pw8hR8ohn967iSDuxaURaOYmKiQf9rHWUB8qb69wh+xHlVtN+kUurfv58WfVlf2SIfnptWVuZEWEWBHXvF95WcXppoUr6jtV2k=" Apr 20 08:33:41 volumio go-librespot[7089]: time="2024-04-20T08:33:41Z" 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]" Apr 20 08:33:41 volumio go-librespot[7089]: time="2024-04-20T08:33:41Z" level=debug msg="completed keyexchange" Apr 20 08:33:42 volumio go-librespot[7089]: time="2024-04-20T08:33:42Z" level=debug msg="completed challenge" Apr 20 08:33:42 volumio go-librespot[7089]: time="2024-04-20T08:33:42Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 20 08:33:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 20 08:33:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 20 08:33:42 volumio volumio[949]: info: Initializing connection to go-librespot Websocket Apr 20 08:33:42 volumio volumio[949]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 20 08:33:45 volumio volumio[949]: info: Initializing connection to go-librespot Websocket Apr 20 08:33:45 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 20 08:33:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2311. Apr 20 08:33:45 volumio systemd[1]: Stopped go-librespot Daemon. Apr 20 08:33:45 volumio volumio[949]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 20 08:33:45 volumio systemd[1]: Started go-librespot Daemon. Apr 20 08:33:45 volumio go-librespot[7105]: Librespot-go daemon starting... Apr 20 08:33:45 volumio go-librespot[7105]: time="2024-04-20T08:33:45Z" level=info msg="generated new device id: 1558119aa6e2f3b0e567b7f29becdc4e46ac33e0" Apr 20 08:33:45 volumio go-librespot[7105]: time="2024-04-20T08:33:45Z" level=debug msg="stored credentials found for vloo68" Apr 20 08:33:45 volumio go-librespot[7105]: time="2024-04-20T08:33:45Z" level=debug msg="obtained new client token: AADuaLMSV51aHtWu/ZUnmVydzlnCV8ZGLzX52r6fH/pwu5qsj7ZoEiu7qvS1vCO7MRs2uWTc7b0P8XzcbjkF9mg3COZq7PjD7DEQGK+BPR4elhsjbzIxKxADitceL9kZAT1PCva+kNEh2eWEYAUlG549uGIJ471+nf4N5XaZlP95hy/PB0EkbXv8u5zz7BDJCKoT1pAeyChL1U4+fJmKSsI/tbm6+4fqifscACZJrzkjgRqu0jc3FQb+tzW/Oe4=" Apr 20 08:33:45 volumio go-librespot[7105]: time="2024-04-20T08:33:45Z" 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]" Apr 20 08:33:45 volumio go-librespot[7105]: time="2024-04-20T08:33:45Z" level=debug msg="completed keyexchange" Apr 20 08:33:46 volumio go-librespot[7105]: time="2024-04-20T08:33:46Z" level=debug msg="completed challenge" Apr 20 08:33:46 volumio go-librespot[7105]: time="2024-04-20T08:33:46Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 20 08:33:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 20 08:33:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 20 08:33:48 volumio volumio[949]: info: Initializing connection to go-librespot Websocket Apr 20 08:33:48 volumio volumio[949]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 20 08:33:49 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 20 08:33:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2312. Apr 20 08:33:49 volumio systemd[1]: Stopped go-librespot Daemon. Apr 20 08:33:49 volumio systemd[1]: Started go-librespot Daemon. Apr 20 08:33:49 volumio go-librespot[7121]: Librespot-go daemon starting... Apr 20 08:33:49 volumio go-librespot[7121]: time="2024-04-20T08:33:49Z" level=info msg="generated new device id: 9b1dcf7cf8a995703c74a298d8fa07b308c3c8bb" Apr 20 08:33:49 volumio go-librespot[7121]: time="2024-04-20T08:33:49Z" level=debug msg="stored credentials found for vloo68" Apr 20 08:33:49 volumio go-librespot[7121]: time="2024-04-20T08:33:49Z" level=debug msg="obtained new client token: AAAFBxAtdsrcKf6oWPj7AoQKLBzCp7co06RiquRaR8Y1gRWOC6ikGQ3HDH4Fq8hviws6gGsAlDo+i6zq9EgfxcRC3YTSGD0vrnIThM5TyRiQjQ5wj2ZbEkD1yYWPVg2VfgnNIFDNo9v0T6CvyifL4ba57c/cedDHyB2PNg7gIhmzN7zCfp2J4IV3VUIYu67SfUbltLZiwx2JRPDSUn/jEd3QYrpOUvZH7n4wB8THb88TSBVulY+9lPB0Dh+PINo=" Apr 20 08:33:49 volumio go-librespot[7121]: time="2024-04-20T08:33:49Z" 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]" Apr 20 08:33:49 volumio go-librespot[7121]: time="2024-04-20T08:33:49Z" level=debug msg="completed keyexchange" Apr 20 08:33:50 volumio go-librespot[7121]: time="2024-04-20T08:33:50Z" level=debug msg="completed challenge" Apr 20 08:33:50 volumio go-librespot[7121]: time="2024-04-20T08:33:50Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 20 08:33:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 20 08:33:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 20 08:33:51 volumio volumio[949]: info: Initializing connection to go-librespot Websocket Apr 20 08:33:51 volumio volumio[949]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 20 08:33:53 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 20 08:33:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2313. Apr 20 08:33:53 volumio systemd[1]: Stopped go-librespot Daemon. Apr 20 08:33:53 volumio systemd[1]: Started go-librespot Daemon. Apr 20 08:33:53 volumio go-librespot[7137]: Librespot-go daemon starting... Apr 20 08:33:53 volumio go-librespot[7137]: time="2024-04-20T08:33:53Z" level=info msg="generated new device id: 88b012d8d657c00bf7347a25040468fc25a0fde6" Apr 20 08:33:53 volumio go-librespot[7137]: time="2024-04-20T08:33:53Z" level=debug msg="stored credentials found for vloo68" Apr 20 08:33:53 volumio go-librespot[7137]: time="2024-04-20T08:33:53Z" level=debug msg="obtained new client token: AAACLaWeIlWMlUYLb7r0dAm8w2tyyJXdFBRhCpDGTtpWliM1LBrA9IV8wcZ2DPhChwYqbuqFJ1mXXk/EeeHTW2DjKlC5xKcONxm5UAfjlTCaz49QhnvQ3V2VdJukxc6mSFeBK1vfP/FuowDvMez4OQ+PapjBms8/80MS56nV5c1w0C6VZiYaD5QCRZfYrsN8+8ExdnPy4fohK9I/rD3X3HJ1MsO2B/Bm5nmZ5rEmbMZHQcnofFTKOPzfpVsYWOk=" Apr 20 08:33:53 volumio go-librespot[7137]: time="2024-04-20T08:33:53Z" 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]" Apr 20 08:33:53 volumio go-librespot[7137]: time="2024-04-20T08:33:53Z" level=debug msg="completed keyexchange" Apr 20 08:33:54 volumio go-librespot[7137]: time="2024-04-20T08:33:54Z" level=debug msg="completed challenge" Apr 20 08:33:54 volumio go-librespot[7137]: time="2024-04-20T08:33:54Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 20 08:33:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 20 08:33:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 20 08:33:54 volumio volumio[949]: info: Initializing connection to go-librespot Websocket Apr 20 08:33:54 volumio volumio[949]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 20 08:33:54 volumio volumio[949]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Apr 20 08:33:54 volumio volumio[949]: info: CURURI: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition) Apr 20 08:33:54 volumio volumio[949]: error: Cue Parser - Cannot parse USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/Surface - Surface.cue Apr 20 08:33:54 volumio volumio[949]: info: Preload queue cleared Apr 20 08:33:54 volumio volumio[949]: info: Preloading song: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/01. Let’s Try Again.flac Apr 20 08:33:54 volumio volumio[949]: info: Preloading song: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/03. We’re All Searchin’.flac Apr 20 08:33:54 volumio volumio[949]: info: Preloading song: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/07. You’re Fine.flac Apr 20 08:33:54 volumio volumio[949]: info: Preloading song: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/15. Let’s Try Again (extended version).flac Apr 20 08:33:54 volumio volumio[949]: info: Preloading song: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/16. Let’s Try Again (instrumental version).flac Apr 20 08:33:54 volumio volumio[949]: info: Preloading song: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/Surface - Surface.m3u Apr 20 08:33:54 volumio volumio[949]: info: Exploding uri music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/01. Let’s Try Again.flac in service mpd Apr 20 08:33:54 volumio volumio[949]: info: ALBUMART /albumart?cacheid=247&web=Surface/Surface/large&path=%2Fmnt%2FUSB%2FMUSICS%2FSurface%20-%201987%20-%20Surface%20(Expanded%20Edition)%2F01.%20Let%E2%80%99s%20Try%20Again.flac&metadata=false Apr 20 08:33:54 volumio volumio[949]: info: URI /mnt/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/01. Let’s Try Again.flac Apr 20 08:33:54 volumio volumio[949]: info: Exploding uri music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/03. We’re All Searchin’.flac in service mpd Apr 20 08:33:54 volumio volumio[949]: info: ALBUMART /albumart?cacheid=247&web=Surface/Surface/large&path=%2Fmnt%2FUSB%2FMUSICS%2FSurface%20-%201987%20-%20Surface%20(Expanded%20Edition)%2F03.%20We%E2%80%99re%20All%20Searchin%E2%80%99.flac&metadata=false Apr 20 08:33:54 volumio volumio[949]: info: URI /mnt/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/03. We’re All Searchin’.flac Apr 20 08:33:54 volumio volumio[949]: info: Exploding uri music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/07. You’re Fine.flac in service mpd Apr 20 08:33:54 volumio volumio[949]: info: ALBUMART /albumart?cacheid=247&web=Surface/Surface/large&path=%2Fmnt%2FUSB%2FMUSICS%2FSurface%20-%201987%20-%20Surface%20(Expanded%20Edition)%2F07.%20You%E2%80%99re%20Fine.flac&metadata=false Apr 20 08:33:54 volumio volumio[949]: info: URI /mnt/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/07. You’re Fine.flac Apr 20 08:33:55 volumio volumio[949]: info: Exploding uri music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/15. Let’s Try Again (extended version).flac in service mpd Apr 20 08:33:55 volumio volumio[949]: info: ALBUMART /albumart?cacheid=247&web=Surface/Surface/large&path=%2Fmnt%2FUSB%2FMUSICS%2FSurface%20-%201987%20-%20Surface%20(Expanded%20Edition)%2F15.%20Let%E2%80%99s%20Try%20Again%20(extended%20version).flac&metadata=false Apr 20 08:33:55 volumio volumio[949]: info: URI /mnt/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/15. Let’s Try Again (extended version).flac Apr 20 08:33:55 volumio volumio[949]: info: Exploding uri music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/16. Let’s Try Again (instrumental version).flac in service mpd Apr 20 08:33:55 volumio volumio[949]: info: ALBUMART /albumart?cacheid=247&web=Surface/Surface/large&path=%2Fmnt%2FUSB%2FMUSICS%2FSurface%20-%201987%20-%20Surface%20(Expanded%20Edition)%2F16.%20Let%E2%80%99s%20Try%20Again%20(instrumental%20version).flac&metadata=false Apr 20 08:33:55 volumio volumio[949]: info: URI /mnt/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/16. Let’s Try Again (instrumental version).flac Apr 20 08:33:55 volumio volumio[949]: info: Exploding uri music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/Surface - Surface.m3u in service mpd Apr 20 08:33:57 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 20 08:33:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2314. Apr 20 08:33:57 volumio systemd[1]: Stopped go-librespot Daemon. Apr 20 08:33:57 volumio volumio[949]: info: Initializing connection to go-librespot Websocket Apr 20 08:33:57 volumio volumio[949]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 20 08:33:57 volumio systemd[1]: Started go-librespot Daemon. Apr 20 08:33:57 volumio go-librespot[7154]: Librespot-go daemon starting... Apr 20 08:33:57 volumio go-librespot[7154]: time="2024-04-20T08:33:57Z" level=info msg="generated new device id: 42e0508fdbf59c96de29df4870c95112466f3967" Apr 20 08:33:57 volumio go-librespot[7154]: time="2024-04-20T08:33:57Z" level=debug msg="stored credentials found for vloo68" Apr 20 08:33:57 volumio go-librespot[7154]: time="2024-04-20T08:33:57Z" level=debug msg="obtained new client token: AACfI8OTA4kTmdk0pMmUnZtyZSUYkInamFvOW6ACIaCoysfp8PHbhE/eYYrnIxvtDXICKIt/mR/VrBDt5SjStrG49iLu+h6v4AxJXkfTSVTtFmEscjZI0dMerS5EQcL9NBuRHpKQ2r4YLFAkhsfwcBvnevQEl0YOzFpM6Ur09r7r5jWBnKLbrB+0H34E7Daq6FFe+neq/kdZ+bzsnkFKKzzrWCnJgkWZQG2cUgkzCAejjwyRTdeJqetT5nT/1SU=" Apr 20 08:33:57 volumio go-librespot[7154]: time="2024-04-20T08:33:57Z" 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]" Apr 20 08:33:57 volumio go-librespot[7154]: time="2024-04-20T08:33:57Z" level=debug msg="completed keyexchange" Apr 20 08:33:58 volumio go-librespot[7154]: time="2024-04-20T08:33:58Z" level=debug msg="completed challenge" Apr 20 08:33:58 volumio go-librespot[7154]: time="2024-04-20T08:33:58Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 20 08:33:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 20 08:33:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 20 08:34:00 volumio volumio[949]: info: Initializing connection to go-librespot Websocket Apr 20 08:34:00 volumio volumio[949]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 20 08:34:01 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 20 08:34:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2315. Apr 20 08:34:01 volumio systemd[1]: Stopped go-librespot Daemon. Apr 20 08:34:01 volumio systemd[1]: Started go-librespot Daemon. Apr 20 08:34:01 volumio go-librespot[7170]: Librespot-go daemon starting... Apr 20 08:34:01 volumio go-librespot[7170]: time="2024-04-20T08:34:01Z" level=info msg="generated new device id: 6b41469d25e984e0e225749f08b8480ba8057f61" Apr 20 08:34:01 volumio go-librespot[7170]: time="2024-04-20T08:34:01Z" level=debug msg="stored credentials found for vloo68" Apr 20 08:34:01 volumio volumio[949]: info: Preload queue cleared Apr 20 08:34:01 volumio volumio[949]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 20 08:34:01 volumio volumio[949]: info: CoreStateMachine::ClearQueue Apr 20 08:34:01 volumio volumio[949]: info: CoreStateMachine::stop Apr 20 08:34:01 volumio volumio[949]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 20 08:34:01 volumio volumio[949]: info: CoreStateMachine::stPlaybackTimer Apr 20 08:34:01 volumio volumio[949]: info: CoreStateMachine::updateTrackBlock Apr 20 08:34:01 volumio volumio[949]: info: CorePlayQueue::getTrackBlock Apr 20 08:34:01 volumio volumio[949]: info: CoreStateMachine::pushState Apr 20 08:34:01 volumio volumio[949]: info: CorePlayQueue::getTrack 0 Apr 20 08:34:01 volumio volumio[949]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 20 08:34:01 volumio volumio[949]: info: CoreCommandRouter::volumioPushState Apr 20 08:34:01 volumio volumio[949]: info: CoreStateMachine::serviceStop Apr 20 08:34:01 volumio volumio[949]: info: CorePlayQueue::getTrack 0 Apr 20 08:34:01 volumio volumio[949]: info: CoreCommandRouter::serviceStop Apr 20 08:34:01 volumio volumio[949]: info: [1713602041500] ControllerWebradio::stop Apr 20 08:34:01 volumio volumio[949]: verbose: ControllerMpd::sendMpdCommand stop Apr 20 08:34:01 volumio volumio[949]: info: CorePlayQueue::clearPlayQueue Apr 20 08:34:01 volumio volumio[949]: info: CorePlayQueue::saveQueue Apr 20 08:34:01 volumio volumio[949]: info: CoreCommandRouter::volumioPushQueue Apr 20 08:34:01 volumio volumio[949]: info: CoreStateMachine::addQueueItems Apr 20 08:34:01 volumio volumio[949]: info: CorePlayQueue::addQueueItems Apr 20 08:34:01 volumio volumio[949]: info: Preload queue cleared Apr 20 08:34:01 volumio volumio[949]: info: Adding Item to queue: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/01. Let’s Try Again.flac Apr 20 08:34:01 volumio volumio[949]: info: Using cached record of: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/01. Let’s Try Again.flac Apr 20 08:34:01 volumio volumio[949]: info: Adding Item to queue: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/03. We’re All Searchin’.flac Apr 20 08:34:01 volumio volumio[949]: info: Using cached record of: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/03. We’re All Searchin’.flac Apr 20 08:34:01 volumio volumio[949]: info: Adding Item to queue: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/07. You’re Fine.flac Apr 20 08:34:01 volumio volumio[949]: info: Using cached record of: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/07. You’re Fine.flac Apr 20 08:34:01 volumio volumio[949]: info: Adding Item to queue: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/15. Let’s Try Again (extended version).flac Apr 20 08:34:01 volumio volumio[949]: info: Using cached record of: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/15. Let’s Try Again (extended version).flac Apr 20 08:34:01 volumio volumio[949]: info: Adding Item to queue: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/16. Let’s Try Again (instrumental version).flac Apr 20 08:34:01 volumio volumio[949]: info: Using cached record of: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/16. Let’s Try Again (instrumental version).flac Apr 20 08:34:01 volumio volumio[949]: info: Adding Item to queue: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/Surface - Surface.m3u Apr 20 08:34:01 volumio volumio[949]: info: Using cached record of: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/Surface - Surface.m3u Apr 20 08:34:01 volumio volumio[949]: info: Adding Item to queue: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/Surface - Surface.cue Apr 20 08:34:01 volumio volumio[949]: info: Exploding uri music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/Surface - Surface.cue in service mpd Apr 20 08:34:01 volumio go-librespot[7170]: time="2024-04-20T08:34:01Z" level=debug msg="obtained new client token: AACTvHbtfIFWtQSfXxh3tEo1ECML8BskN2zGNMMa6gMAZ0wClrnHTewNqfzEWiqcseTDhUkXFIv875DFIjjPNWy0B+X2/mk/kPs/1+LWfUD3ugO/m6hu8f2l4hbV19rDAwJ3l98GlSrahNKA/jmd5iReYz2aIQg7NDiZAFgixm0xBdU/siDFZpoaEGY6/VWNBRl+sFGO1zN4EXvb/46wS8HnTlkPYKb5drATX9DkSiJMwd/NIY9E9GEGZKpQN08=" Apr 20 08:34:01 volumio volumio[949]: error: The value "windows-1252" is invalid for option "encoding" {"code":"ERR_INVALID_OPT_VALUE_ENCODING"} Apr 20 08:34:01 volumio volumio[949]: error: Cue Parser - Cannot parse /mnt/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/Surface - Surface.cue Apr 20 08:34:01 volumio volumio[949]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Apr 20 08:34:01 volumio volumio[949]: info: Apr 20 08:34:01 volumio volumio[949]: ---------------------------- MPD announces state update: player Apr 20 08:34:01 volumio volumio[949]: info: sendMpdCommand stop took 87 milliseconds Apr 20 08:34:01 volumio volumio[949]: info: ControllerMpd::getState Apr 20 08:34:01 volumio volumio[949]: verbose: ControllerMpd::sendMpdCommand status Apr 20 08:34:01 volumio volumio[949]: info: sendMpdCommand status took 2 milliseconds Apr 20 08:34:01 volumio volumio[949]: verbose: ControllerMpd::parseState Apr 20 08:34:01 volumio volumio[949]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 20 08:34:01 volumio volumio[949]: info: Apr 20 08:34:01 volumio volumio[949]: ---------------------------- MPD announces state update: player Apr 20 08:34:01 volumio volumio[949]: info: ControllerMpd::getState Apr 20 08:34:01 volumio volumio[949]: verbose: ControllerMpd::sendMpdCommand status Apr 20 08:34:01 volumio volumio[949]: info: Apr 20 08:34:01 volumio volumio[949]: ---------------------------- MPD announces state update: player Apr 20 08:34:01 volumio volumio[949]: info: ControllerMpd::getState Apr 20 08:34:01 volumio volumio[949]: verbose: ControllerMpd::sendMpdCommand status Apr 20 08:34:01 volumio volumio[949]: info: sendMpdCommand playlistinfo took 8 milliseconds Apr 20 08:34:01 volumio volumio[949]: info: sendMpdCommand status took 4 milliseconds Apr 20 08:34:01 volumio volumio[949]: info: sendMpdCommand status took 3 milliseconds Apr 20 08:34:01 volumio volumio[949]: verbose: ControllerMpd::parseTrackInfo Apr 20 08:34:01 volumio volumio[949]: verbose: ControllerMpd::parseState Apr 20 08:34:01 volumio volumio[949]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 20 08:34:01 volumio volumio[949]: verbose: ControllerMpd::parseState Apr 20 08:34:01 volumio volumio[949]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 20 08:34:01 volumio volumio[949]: info: ControllerMpd::pushState Apr 20 08:34:01 volumio volumio[949]: info: CoreCommandRouter::servicePushState Apr 20 08:34:01 volumio go-librespot[7170]: time="2024-04-20T08:34:01Z" 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]" Apr 20 08:34:01 volumio volumio[949]: info: CoreStateMachine::pushState Apr 20 08:34:01 volumio volumio[949]: info: CorePlayQueue::getTrack 0 Apr 20 08:34:01 volumio volumio[949]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 20 08:34:01 volumio volumio[949]: info: CoreCommandRouter::volumioPushState Apr 20 08:34:01 volumio volumio[949]: info: CorePlayQueue::getTrack 0 Apr 20 08:34:01 volumio volumio[949]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"The Frost Duo - Saturate ","artist":"SmoothJazz.com","album":null,"uri":"http://smoothjazz.cdnstream1.com/2585_320.mp3","trackType":"mp3"} Apr 20 08:34:01 volumio volumio[949]: verbose: CURRENT POSITION 0 Apr 20 08:34:01 volumio volumio[949]: info: CoreStateMachine::syncState stateService stop Apr 20 08:34:01 volumio volumio[949]: info: CoreStateMachine::syncState currentStatus stop Apr 20 08:34:01 volumio volumio[949]: info: CoreStateMachine::pushState Apr 20 08:34:01 volumio volumio[949]: info: CorePlayQueue::getTrack 0 Apr 20 08:34:01 volumio volumio[949]: info: CoreCommandRouter::volumioPushState Apr 20 08:34:01 volumio volumio[949]: info: No code Apr 20 08:34:01 volumio volumio[949]: info: CoreStateMachine::pushState Apr 20 08:34:01 volumio volumio[949]: info: CorePlayQueue::getTrack 0 Apr 20 08:34:01 volumio volumio[949]: info: CoreCommandRouter::volumioPushState Apr 20 08:34:01 volumio volumio[949]: info: ------------------------------ 50ms Apr 20 08:34:01 volumio volumio[949]: info: sendMpdCommand playlistinfo took 29 milliseconds Apr 20 08:34:01 volumio volumio[949]: info: sendMpdCommand playlistinfo took 30 milliseconds Apr 20 08:34:01 volumio volumio[949]: verbose: ControllerMpd::parseTrackInfo Apr 20 08:34:01 volumio volumio[949]: verbose: ControllerMpd::parseTrackInfo Apr 20 08:34:01 volumio volumio[949]: info: ControllerMpd::pushState Apr 20 08:34:01 volumio volumio[949]: info: CoreCommandRouter::servicePushState Apr 20 08:34:01 volumio volumio[949]: info: CoreStateMachine::pushState Apr 20 08:34:01 volumio volumio[949]: info: CorePlayQueue::getTrack 0 Apr 20 08:34:01 volumio volumio[949]: info: CoreCommandRouter::volumioPushState Apr 20 08:34:01 volumio volumio[949]: info: CorePlayQueue::getTrack 0 Apr 20 08:34:01 volumio volumio[949]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"The Frost Duo - Saturate ","artist":"SmoothJazz.com","album":null,"uri":"http://smoothjazz.cdnstream1.com/2585_320.mp3","trackType":"mp3"} Apr 20 08:34:01 volumio volumio[949]: verbose: CURRENT POSITION 0 Apr 20 08:34:01 volumio volumio[949]: info: CoreStateMachine::syncState stateService stop Apr 20 08:34:01 volumio volumio[949]: info: CoreStateMachine::syncState currentStatus stop Apr 20 08:34:01 volumio volumio[949]: info: CoreStateMachine::pushState Apr 20 08:34:01 volumio volumio[949]: info: CorePlayQueue::getTrack 0 Apr 20 08:34:01 volumio volumio[949]: info: CoreCommandRouter::volumioPushState Apr 20 08:34:01 volumio volumio[949]: info: No code Apr 20 08:34:01 volumio volumio[949]: info: CoreStateMachine::pushState Apr 20 08:34:01 volumio volumio[949]: info: CorePlayQueue::getTrack 0 Apr 20 08:34:01 volumio volumio[949]: info: CoreCommandRouter::volumioPushState Apr 20 08:34:01 volumio volumio[949]: info: ControllerMpd::pushState Apr 20 08:34:01 volumio volumio[949]: info: CoreCommandRouter::servicePushState Apr 20 08:34:01 volumio volumio[949]: info: CoreStateMachine::pushState Apr 20 08:34:01 volumio volumio[949]: info: CorePlayQueue::getTrack 0 Apr 20 08:34:01 volumio volumio[949]: info: CoreCommandRouter::volumioPushState Apr 20 08:34:01 volumio volumio[949]: info: CorePlayQueue::getTrack 0 Apr 20 08:34:01 volumio volumio[949]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"The Frost Duo - Saturate ","artist":"SmoothJazz.com","album":null,"uri":"http://smoothjazz.cdnstream1.com/2585_320.mp3","trackType":"mp3"} Apr 20 08:34:01 volumio volumio[949]: verbose: CURRENT POSITION 0 Apr 20 08:34:01 volumio volumio[949]: info: CoreStateMachine::syncState stateService stop Apr 20 08:34:01 volumio volumio[949]: info: CoreStateMachine::syncState currentStatus stop Apr 20 08:34:01 volumio volumio[949]: info: CoreStateMachine::pushState Apr 20 08:34:01 volumio volumio[949]: info: CorePlayQueue::getTrack 0 Apr 20 08:34:01 volumio volumio[949]: info: CoreCommandRouter::volumioPushState Apr 20 08:34:01 volumio volumio[949]: info: No code Apr 20 08:34:01 volumio volumio[949]: info: CoreStateMachine::pushState Apr 20 08:34:01 volumio volumio[949]: info: CorePlayQueue::getTrack 0 Apr 20 08:34:01 volumio volumio[949]: info: CoreCommandRouter::volumioPushState Apr 20 08:34:01 volumio volumio[949]: info: ------------------------------ 81ms Apr 20 08:34:01 volumio volumio[949]: info: ------------------------------ 79ms Apr 20 08:34:01 volumio go-librespot[7170]: time="2024-04-20T08:34:01Z" level=debug msg="completed keyexchange" Apr 20 08:34:01 volumio volumio[949]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Apr 20 08:34:01 volumio volumio[949]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Apr 20 08:34:01 volumio volumio[949]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Apr 20 08:34:01 volumio volumio[949]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Apr 20 08:34:01 volumio volumio[949]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Apr 20 08:34:01 volumio volumio[949]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Apr 20 08:34:01 volumio volumio[949]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Apr 20 08:34:01 volumio volumio[949]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Apr 20 08:34:01 volumio volumio[949]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Apr 20 08:34:02 volumio go-librespot[7170]: time="2024-04-20T08:34:02Z" level=debug msg="completed challenge" Apr 20 08:34:02 volumio go-librespot[7170]: time="2024-04-20T08:34:02Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 20 08:34:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 20 08:34:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 20 08:34:03 volumio volumio[949]: info: Initializing connection to go-librespot Websocket Apr 20 08:34:03 volumio volumio[949]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 20 08:34:05 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 20 08:34:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2316. Apr 20 08:34:05 volumio systemd[1]: Stopped go-librespot Daemon. Apr 20 08:34:05 volumio systemd[1]: Started go-librespot Daemon. Apr 20 08:34:05 volumio go-librespot[7181]: Librespot-go daemon starting... Apr 20 08:34:05 volumio go-librespot[7181]: time="2024-04-20T08:34:05Z" level=info msg="generated new device id: c8aa445f46b63de5e8e95e1286cab250e376d6a7" Apr 20 08:34:05 volumio go-librespot[7181]: time="2024-04-20T08:34:05Z" level=debug msg="stored credentials found for vloo68" Apr 20 08:34:05 volumio go-librespot[7181]: time="2024-04-20T08:34:05Z" level=debug msg="obtained new client token: AAAk/E/ep/NJC2VG7rL/v2Rp7FQXboW42wRN240hqXDIMzB214bfE7tIUqdKAENn/fIL46KMUj9Yr7pW9DFqJ6J0CdRMpXV5PG0KqitKg3uVltokBhx/ydqmkEd44RtT5fFdfYoRkaWgUtIMUzz0jealKXSFiBAv/WwOJ9hY1PaOgxJ9V/19Ch0vK8NArG3iA/TEq/uOeZJwtQxCvvJ3VyoNAJInEvD0Ob1KGjETna23ZA2NdgcGI8iO/oh1Ids=" Apr 20 08:34:05 volumio go-librespot[7181]: time="2024-04-20T08:34:05Z" 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]" Apr 20 08:34:05 volumio go-librespot[7181]: time="2024-04-20T08:34:05Z" level=debug msg="completed keyexchange" Apr 20 08:34:06 volumio volumio[949]: info: Initializing connection to go-librespot Websocket Apr 20 08:34:06 volumio go-librespot[7181]: time="2024-04-20T08:34:06Z" level=debug msg="new websocket client" Apr 20 08:34:06 volumio volumio[949]: info: Connection to go-librespot Websocket established Apr 20 08:34:06 volumio go-librespot[7181]: time="2024-04-20T08:34:06Z" level=debug msg="completed challenge" Apr 20 08:34:06 volumio go-librespot[7181]: time="2024-04-20T08:34:06Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 20 08:34:06 volumio volumio[949]: info: Connection to go-librespot Websocket closed Apr 20 08:34:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 20 08:34:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 20 08:34:07 volumio volumio[949]: info: Preload queue cleared Apr 20 08:34:07 volumio volumio[949]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 20 08:34:07 volumio volumio[949]: info: CoreStateMachine::ClearQueue Apr 20 08:34:07 volumio volumio[949]: info: CoreStateMachine::stop Apr 20 08:34:07 volumio volumio[949]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 20 08:34:07 volumio volumio[949]: info: CorePlayQueue::clearPlayQueue Apr 20 08:34:07 volumio volumio[949]: info: CorePlayQueue::saveQueue Apr 20 08:34:07 volumio volumio[949]: info: CoreCommandRouter::volumioPushQueue Apr 20 08:34:07 volumio volumio[949]: info: CoreStateMachine::addQueueItems Apr 20 08:34:07 volumio volumio[949]: info: CorePlayQueue::addQueueItems Apr 20 08:34:07 volumio volumio[949]: info: Preload queue cleared Apr 20 08:34:07 volumio volumio[949]: info: Adding Item to queue: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/01. Let’s Try Again.flac Apr 20 08:34:07 volumio volumio[949]: info: Using cached record of: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/01. Let’s Try Again.flac Apr 20 08:34:07 volumio volumio[949]: info: Adding Item to queue: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/03. We’re All Searchin’.flac Apr 20 08:34:07 volumio volumio[949]: info: Using cached record of: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/03. We’re All Searchin’.flac Apr 20 08:34:07 volumio volumio[949]: info: Adding Item to queue: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/07. You’re Fine.flac Apr 20 08:34:07 volumio volumio[949]: info: Using cached record of: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/07. You’re Fine.flac Apr 20 08:34:07 volumio volumio[949]: info: Adding Item to queue: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/15. Let’s Try Again (extended version).flac Apr 20 08:34:07 volumio volumio[949]: info: Using cached record of: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/15. Let’s Try Again (extended version).flac Apr 20 08:34:07 volumio volumio[949]: info: Adding Item to queue: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/16. Let’s Try Again (instrumental version).flac Apr 20 08:34:07 volumio volumio[949]: info: Using cached record of: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/16. Let’s Try Again (instrumental version).flac Apr 20 08:34:07 volumio volumio[949]: info: Adding Item to queue: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/Surface - Surface.m3u Apr 20 08:34:07 volumio volumio[949]: info: Using cached record of: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/Surface - Surface.m3u Apr 20 08:34:07 volumio volumio[949]: info: Adding Item to queue: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/Surface - Surface.cue Apr 20 08:34:07 volumio volumio[949]: info: Exploding uri music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/Surface - Surface.cue in service mpd Apr 20 08:34:07 volumio volumio[949]: error: The value "windows-1252" is invalid for option "encoding" {"code":"ERR_INVALID_OPT_VALUE_ENCODING"} Apr 20 08:34:07 volumio volumio[949]: error: Cue Parser - Cannot parse /mnt/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/Surface - Surface.cue Apr 20 08:34:09 volumio volumio[949]: info: Getting Spotify volume Apr 20 08:34:09 volumio volumio[949]: (node:949) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 20 08:34:09 volumio volumio[949]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 20 08:34:09 volumio volumio[949]: (node:949) 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: 236) Apr 20 08:34:09 volumio volumio[949]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 Apr 20 08:34:09 volumio volumio[949]: info: CoreCommandRouter::volumioGetState Apr 20 08:34:09 volumio volumio[949]: info: CorePlayQueue::getTrack 0 Apr 20 08:34:09 volumio volumio[949]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Apr 20 08:34:09 volumio volumio[949]: info: Initializing connection to go-librespot Websocket Apr 20 08:34:09 volumio volumio[949]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 20 08:34:09 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 20 08:34:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2317. Apr 20 08:34:09 volumio systemd[1]: Stopped go-librespot Daemon. Apr 20 08:34:09 volumio systemd[1]: Started go-librespot Daemon. Apr 20 08:34:09 volumio go-librespot[7192]: Librespot-go daemon starting... Apr 20 08:34:09 volumio go-librespot[7192]: time="2024-04-20T08:34:09Z" level=info msg="generated new device id: d08c3ef7770b108cf980e64953a3658837559911" Apr 20 08:34:09 volumio go-librespot[7192]: time="2024-04-20T08:34:09Z" level=debug msg="stored credentials found for vloo68" Apr 20 08:34:09 volumio volumio[949]: info: Preload queue cleared Apr 20 08:34:09 volumio volumio[949]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 20 08:34:09 volumio volumio[949]: info: CoreStateMachine::ClearQueue Apr 20 08:34:09 volumio volumio[949]: info: CoreStateMachine::stop Apr 20 08:34:09 volumio volumio[949]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 20 08:34:09 volumio volumio[949]: info: CorePlayQueue::clearPlayQueue Apr 20 08:34:09 volumio volumio[949]: info: CorePlayQueue::saveQueue Apr 20 08:34:09 volumio volumio[949]: info: CoreCommandRouter::volumioPushQueue Apr 20 08:34:09 volumio volumio[949]: info: CoreStateMachine::addQueueItems Apr 20 08:34:09 volumio volumio[949]: info: CorePlayQueue::addQueueItems Apr 20 08:34:09 volumio volumio[949]: info: Preload queue cleared Apr 20 08:34:09 volumio volumio[949]: info: Adding Item to queue: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/01. Let’s Try Again.flac Apr 20 08:34:09 volumio volumio[949]: info: Using cached record of: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/01. Let’s Try Again.flac Apr 20 08:34:09 volumio volumio[949]: info: Adding Item to queue: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/03. We’re All Searchin’.flac Apr 20 08:34:09 volumio volumio[949]: info: Using cached record of: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/03. We’re All Searchin’.flac Apr 20 08:34:09 volumio volumio[949]: info: Adding Item to queue: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/07. You’re Fine.flac Apr 20 08:34:09 volumio volumio[949]: info: Using cached record of: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/07. You’re Fine.flac Apr 20 08:34:09 volumio volumio[949]: info: Adding Item to queue: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/15. Let’s Try Again (extended version).flac Apr 20 08:34:09 volumio volumio[949]: info: Using cached record of: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/15. Let’s Try Again (extended version).flac Apr 20 08:34:09 volumio volumio[949]: info: Adding Item to queue: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/16. Let’s Try Again (instrumental version).flac Apr 20 08:34:09 volumio volumio[949]: info: Using cached record of: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/16. Let’s Try Again (instrumental version).flac Apr 20 08:34:09 volumio volumio[949]: info: Adding Item to queue: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/Surface - Surface.m3u Apr 20 08:34:09 volumio volumio[949]: info: Using cached record of: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/Surface - Surface.m3u Apr 20 08:34:09 volumio volumio[949]: info: Adding Item to queue: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/Surface - Surface.cue Apr 20 08:34:09 volumio volumio[949]: info: Exploding uri music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/Surface - Surface.cue in service mpd Apr 20 08:34:09 volumio volumio[949]: error: The value "windows-1252" is invalid for option "encoding" {"code":"ERR_INVALID_OPT_VALUE_ENCODING"} Apr 20 08:34:09 volumio volumio[949]: error: Cue Parser - Cannot parse /mnt/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/Surface - Surface.cue Apr 20 08:34:09 volumio go-librespot[7192]: time="2024-04-20T08:34:09Z" level=debug msg="obtained new client token: AAAjUW+MeQ+NJpdVXi9t02voz5aZOLzWcw8ZSfx/zTutYRR+RvSdHs937clyPx8lOhePhhqLLWTZl9niAN8XxOAc2aPA4gK3NuNUEygvnXIHoaYDHhM4c8NlTrJxE7vd3Sz/wL39AfKS8Q+qa0MC0kXFfG3wPEVNkEHHj66zftg7Q1tliI2/mroU9VM+5koLno/ate6jS+bquKCaWtPa0CdPdBIcdga/rZCBseeMZmHvaSN6m84qd1mOm9YXvfY=" Apr 20 08:34:09 volumio go-librespot[7192]: time="2024-04-20T08:34:09Z" 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]" Apr 20 08:34:09 volumio go-librespot[7192]: time="2024-04-20T08:34:09Z" level=debug msg="completed keyexchange" Apr 20 08:34:10 volumio go-librespot[7192]: time="2024-04-20T08:34:10Z" level=debug msg="completed challenge" Apr 20 08:34:10 volumio go-librespot[7192]: time="2024-04-20T08:34:10Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 20 08:34:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 20 08:34:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 20 08:34:12 volumio volumio[949]: info: CoreCommandRouter::volumioGetState Apr 20 08:34:12 volumio volumio[949]: info: CorePlayQueue::getTrack 0 Apr 20 08:34:12 volumio volumio[949]: info: Initializing connection to go-librespot Websocket Apr 20 08:34:12 volumio volumio[949]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 20 08:34:13 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 20 08:34:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2318. Apr 20 08:34:13 volumio systemd[1]: Stopped go-librespot Daemon. Apr 20 08:34:13 volumio systemd[1]: Started go-librespot Daemon. Apr 20 08:34:13 volumio go-librespot[7200]: Librespot-go daemon starting... Apr 20 08:34:13 volumio go-librespot[7200]: time="2024-04-20T08:34:13Z" level=info msg="generated new device id: 57aea1c5976f1dec67fc676fbfe9e8c2382e42b8" Apr 20 08:34:13 volumio go-librespot[7200]: time="2024-04-20T08:34:13Z" level=debug msg="stored credentials found for vloo68" Apr 20 08:34:13 volumio go-librespot[7200]: time="2024-04-20T08:34:13Z" level=debug msg="obtained new client token: AACN7+iXtbqU6U98Z+6qU9yLPu4O2FD8qC/1Baoot4ibYgJFRQ2CBak0pn6fI96ERNTqiPHOVE3Jx1+dQ1oPfz/7S95NCPdNysIBwQEZEinHGZQy1h0Pj1ZaQN0WhFRv2qfcSAOOLqvkK1svw1tfOOeajh3v46pABwGtDaP9mJ8ijDs8esVEhnqtPPQQcVRip9aoKhBk92eaH9Hn5PQqwP60GEWPwY2BQYbHYbdOzuYpLsfQgtIqiFt8NOYvi8c=" Apr 20 08:34:13 volumio volumio[949]: info: Preload queue cleared Apr 20 08:34:13 volumio volumio[949]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 20 08:34:13 volumio volumio[949]: info: CoreStateMachine::ClearQueue Apr 20 08:34:13 volumio volumio[949]: info: CoreStateMachine::stop Apr 20 08:34:13 volumio volumio[949]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 20 08:34:13 volumio volumio[949]: info: CorePlayQueue::clearPlayQueue Apr 20 08:34:13 volumio volumio[949]: info: CorePlayQueue::saveQueue Apr 20 08:34:13 volumio volumio[949]: info: CoreCommandRouter::volumioPushQueue Apr 20 08:34:13 volumio volumio[949]: info: CoreStateMachine::addQueueItems Apr 20 08:34:13 volumio volumio[949]: info: CorePlayQueue::addQueueItems Apr 20 08:34:13 volumio volumio[949]: info: Preload queue cleared Apr 20 08:34:13 volumio volumio[949]: info: Adding Item to queue: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/01. Let’s Try Again.flac Apr 20 08:34:13 volumio volumio[949]: info: Using cached record of: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/01. Let’s Try Again.flac Apr 20 08:34:13 volumio volumio[949]: info: Adding Item to queue: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/03. We’re All Searchin’.flac Apr 20 08:34:13 volumio volumio[949]: info: Using cached record of: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/03. We’re All Searchin’.flac Apr 20 08:34:13 volumio volumio[949]: info: Adding Item to queue: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/07. You’re Fine.flac Apr 20 08:34:13 volumio volumio[949]: info: Using cached record of: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/07. You’re Fine.flac Apr 20 08:34:13 volumio volumio[949]: info: Adding Item to queue: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/15. Let’s Try Again (extended version).flac Apr 20 08:34:13 volumio volumio[949]: info: Using cached record of: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/15. Let’s Try Again (extended version).flac Apr 20 08:34:13 volumio volumio[949]: info: Adding Item to queue: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/16. Let’s Try Again (instrumental version).flac Apr 20 08:34:13 volumio volumio[949]: info: Using cached record of: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/16. Let’s Try Again (instrumental version).flac Apr 20 08:34:13 volumio volumio[949]: info: Adding Item to queue: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/Surface - Surface.m3u Apr 20 08:34:13 volumio volumio[949]: info: Using cached record of: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/Surface - Surface.m3u Apr 20 08:34:13 volumio volumio[949]: info: Adding Item to queue: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/Surface - Surface.cue Apr 20 08:34:13 volumio volumio[949]: info: Exploding uri music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/Surface - Surface.cue in service mpd Apr 20 08:34:13 volumio volumio[949]: error: The value "windows-1252" is invalid for option "encoding" {"code":"ERR_INVALID_OPT_VALUE_ENCODING"} Apr 20 08:34:13 volumio volumio[949]: error: Cue Parser - Cannot parse /mnt/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/Surface - Surface.cue Apr 20 08:34:13 volumio go-librespot[7200]: time="2024-04-20T08:34:13Z" 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]" Apr 20 08:34:13 volumio go-librespot[7200]: time="2024-04-20T08:34:13Z" level=debug msg="completed keyexchange" Apr 20 08:34:14 volumio go-librespot[7200]: time="2024-04-20T08:34:14Z" level=debug msg="completed challenge" Apr 20 08:34:14 volumio go-librespot[7200]: time="2024-04-20T08:34:14Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 20 08:34:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 20 08:34:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 20 08:34:15 volumio volumio[949]: info: Initializing connection to go-librespot Websocket Apr 20 08:34:15 volumio volumio[949]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 20 08:34:17 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 20 08:34:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2319. Apr 20 08:34:17 volumio systemd[1]: Stopped go-librespot Daemon. Apr 20 08:34:17 volumio systemd[1]: Started go-librespot Daemon. Apr 20 08:34:17 volumio go-librespot[7247]: Librespot-go daemon starting... Apr 20 08:34:17 volumio go-librespot[7247]: time="2024-04-20T08:34:17Z" level=info msg="generated new device id: b21c00ae2248191531018b110aac0581c2f8de03" Apr 20 08:34:17 volumio go-librespot[7247]: time="2024-04-20T08:34:17Z" level=debug msg="stored credentials found for vloo68" Apr 20 08:34:17 volumio go-librespot[7247]: time="2024-04-20T08:34:17Z" level=debug msg="obtained new client token: AAASD0FnYHzfY+cGNH4SEmQxqKxKMUlhRs/cSvaEZa79wVz+6K8Y+fbAFrSdJTjeffuQ/jogd78MRqkrfF7w8lfrkGYafYcDHUsdCGOpaEEOVid30jxODy5EO8YM7AcdRshrNoK8znp8+cqTymnIYfL/cbtYlux63Y3wSMqNfZDtTsb1zd5k/eTuT7WMKsA7Kca+6/VQUng5cRenDrU/dFsuFHvwmT1hZ+llZ4s0wu0CIiW6ryd7TFaT9jsJnus=" Apr 20 08:34:17 volumio go-librespot[7247]: time="2024-04-20T08:34:17Z" 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]" Apr 20 08:34:17 volumio go-librespot[7247]: time="2024-04-20T08:34:17Z" level=debug msg="completed keyexchange" Apr 20 08:34:18 volumio go-librespot[7247]: time="2024-04-20T08:34:18Z" level=debug msg="completed challenge" Apr 20 08:34:18 volumio go-librespot[7247]: time="2024-04-20T08:34:18Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 20 08:34:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 20 08:34:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 20 08:34:18 volumio volumio[949]: info: Initializing connection to go-librespot Websocket Apr 20 08:34:18 volumio volumio[949]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 20 08:34:21 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 20 08:34:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2320. Apr 20 08:34:21 volumio volumio[949]: info: Initializing connection to go-librespot Websocket Apr 20 08:34:21 volumio systemd[1]: Stopped go-librespot Daemon. Apr 20 08:34:21 volumio volumio[949]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 20 08:34:21 volumio systemd[1]: Started go-librespot Daemon. Apr 20 08:34:21 volumio go-librespot[7255]: Librespot-go daemon starting... Apr 20 08:34:21 volumio go-librespot[7255]: time="2024-04-20T08:34:21Z" level=info msg="generated new device id: 967b52b48efe607e40d9faf66bef39a05a2dee9f" Apr 20 08:34:21 volumio go-librespot[7255]: time="2024-04-20T08:34:21Z" level=debug msg="stored credentials found for vloo68" Apr 20 08:34:21 volumio go-librespot[7255]: time="2024-04-20T08:34:21Z" level=debug msg="obtained new client token: AACsft/gi1viflGn4yLM6UYnD4LBY3zwJcXETmcvg3f+OhRuVNVt8uGd83Srs761k/fvyuetWFIODr7IZiI+0/DBVJ2L+/6chg6Cu2huPJLIgFCz4hG7PFpvy2SbzNfLI3lGj75PmYSEkFkECxVb/c4IaVKqYHsSPm9AVBz+eG1yQICNh6sURzMSgL7zHUS1jSmuXp7FST8Yax49wttQ+LsfP4Q7Q9lKWvyvRYbbpGDzK5595sE2BlAEBcarmKI=" Apr 20 08:34:21 volumio go-librespot[7255]: time="2024-04-20T08:34:21Z" 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]" Apr 20 08:34:21 volumio go-librespot[7255]: time="2024-04-20T08:34:21Z" level=debug msg="completed keyexchange" Apr 20 08:34:22 volumio go-librespot[7255]: time="2024-04-20T08:34:22Z" level=debug msg="completed challenge" Apr 20 08:34:22 volumio go-librespot[7255]: time="2024-04-20T08:34:22Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 20 08:34:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 20 08:34:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 20 08:34:22 volumio volumio[949]: info: Preload queue cleared Apr 20 08:34:22 volumio volumio[949]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 20 08:34:22 volumio volumio[949]: info: CoreStateMachine::ClearQueue Apr 20 08:34:22 volumio volumio[949]: info: CoreStateMachine::stop Apr 20 08:34:22 volumio volumio[949]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 20 08:34:22 volumio volumio[949]: info: CorePlayQueue::clearPlayQueue Apr 20 08:34:22 volumio volumio[949]: info: CorePlayQueue::saveQueue Apr 20 08:34:22 volumio volumio[949]: info: CoreCommandRouter::volumioPushQueue Apr 20 08:34:22 volumio volumio[949]: info: CoreStateMachine::addQueueItems Apr 20 08:34:22 volumio volumio[949]: info: CorePlayQueue::addQueueItems Apr 20 08:34:22 volumio volumio[949]: info: Preload queue cleared Apr 20 08:34:22 volumio volumio[949]: info: Adding Item to queue: music-library/USB/MUSICS/Stars On 45 - The Very Best Of Stars On 45 [Edel Records - 0163732 ERE][CD, Compilation, Germany, 2005][FLAC] Apr 20 08:34:22 volumio volumio[949]: info: Exploding uri music-library/USB/MUSICS/Stars On 45 - The Very Best Of Stars On 45 [Edel Records - 0163732 ERE][CD, Compilation, Germany, 2005][FLAC] in service mpd Apr 20 08:34:22 volumio volumio[949]: info: ALBUMART /albumart?cacheid=247&web=Stars%20On%2045/The%20Very%20Best%20Of%20Stars%20On%2045%20%5BEdel%20Records%20-%200163732%20ERE%5D/large&path=%2Fmnt%2FUSB%2FMUSICS%2FStars%20On%2045%20-%20The%20Very%20Best%20Of%20Stars%20On%2045%20%5BEdel%20Records%20-%200163732%20ERE%5D%5BCD%2C%20Compilation%2C%20Germany%2C%202005%5D%5BFLAC%5D%2F01.%20Stars%20On%2045%20-%20Stars%20On%2045%20(Original%20Single%20Version).flac&metadata=false Apr 20 08:34:22 volumio volumio[949]: info: URI /mnt/USB/MUSICS/Stars On 45 - The Very Best Of Stars On 45 [Edel Records - 0163732 ERE][CD, Compilation, Germany, 2005][FLAC]/01. Stars On 45 - Stars On 45 (Original Single Version).flac Apr 20 08:34:22 volumio volumio[949]: info: ALBUMART /albumart?cacheid=247&web=Stars%20On%2045/The%20Very%20Best%20Of%20Stars%20On%2045%20%5BEdel%20Records%20-%200163732%20ERE%5D/large&path=%2Fmnt%2FUSB%2FMUSICS%2FStars%20On%2045%20-%20The%20Very%20Best%20Of%20Stars%20On%2045%20%5BEdel%20Records%20-%200163732%20ERE%5D%5BCD%2C%20Compilation%2C%20Germany%2C%202005%5D%5BFLAC%5D%2F02.%20Stars%20On%2045%20-%20Stars%20On%2045%20(Original%2012-inch%20Version).flac&metadata=false Apr 20 08:34:22 volumio volumio[949]: info: URI /mnt/USB/MUSICS/Stars On 45 - The Very Best Of Stars On 45 [Edel Records - 0163732 ERE][CD, Compilation, Germany, 2005][FLAC]/02. Stars On 45 - Stars On 45 (Original 12-inch Version).flac Apr 20 08:34:22 volumio volumio[949]: info: ALBUMART /albumart?cacheid=247&web=Stars%20On%2045/The%20Very%20Best%20Of%20Stars%20On%2045%20%5BEdel%20Records%20-%200163732%20ERE%5D/large&path=%2Fmnt%2FUSB%2FMUSICS%2FStars%20On%2045%20-%20The%20Very%20Best%20Of%20Stars%20On%2045%20%5BEdel%20Records%20-%200163732%20ERE%5D%5BCD%2C%20Compilation%2C%20Germany%2C%202005%5D%5BFLAC%5D%2F03.%20Stars%20On%2045%20-%20More%20Stars%20(Abba%20Medley)%20(Original%20Single%20Version).flac&metadata=false Apr 20 08:34:22 volumio volumio[949]: info: URI /mnt/USB/MUSICS/Stars On 45 - The Very Best Of Stars On 45 [Edel Records - 0163732 ERE][CD, Compilation, Germany, 2005][FLAC]/03. Stars On 45 - More Stars (Abba Medley) (Original Single Version).flac Apr 20 08:34:22 volumio volumio[949]: info: ALBUMART /albumart?cacheid=247&web=Stars%20On%2045/The%20Very%20Best%20Of%20Stars%20On%2045%20%5BEdel%20Records%20-%200163732%20ERE%5D/large&path=%2Fmnt%2FUSB%2FMUSICS%2FStars%20On%2045%20-%20The%20Very%20Best%20Of%20Stars%20On%2045%20%5BEdel%20Records%20-%200163732%20ERE%5D%5BCD%2C%20Compilation%2C%20Germany%2C%202005%5D%5BFLAC%5D%2F04.%20Stars%20On%2045%20-%20More%20Stars%20(U.S.A.%20Version)%20(Original%2012%20Inch%20Version).flac&metadata=false Apr 20 08:34:22 volumio volumio[949]: info: URI /mnt/USB/MUSICS/Stars On 45 - The Very Best Of Stars On 45 [Edel Records - 0163732 ERE][CD, Compilation, Germany, 2005][FLAC]/04. Stars On 45 - More Stars (U.S.A. Version) (Original 12 Inch Version).flac Apr 20 08:34:22 volumio volumio[949]: info: ALBUMART /albumart?cacheid=247&web=Stars%20On%2045/The%20Very%20Best%20Of%20Stars%20On%2045%20%5BEdel%20Records%20-%200163732%20ERE%5D/large&path=%2Fmnt%2FUSB%2FMUSICS%2FStars%20On%2045%20-%20The%20Very%20Best%20Of%20Stars%20On%2045%20%5BEdel%20Records%20-%200163732%20ERE%5D%5BCD%2C%20Compilation%2C%20Germany%2C%202005%5D%5BFLAC%5D%2F05.%20Stars%20On%2045%20-%20Volume%20III%20(Star%20Wars%20And%20Other%20Hits)%20(Original%2012%20Inch%20Version).flac&metadata=false Apr 20 08:34:22 volumio volumio[949]: info: URI /mnt/USB/MUSICS/Stars On 45 - The Very Best Of Stars On 45 [Edel Records - 0163732 ERE][CD, Compilation, Germany, 2005][FLAC]/05. Stars On 45 - Volume III (Star Wars And Other Hits) (Original 12 Inch Version).flac Apr 20 08:34:22 volumio volumio[949]: info: ALBUMART /albumart?cacheid=247&web=Stars%20On%2045/The%20Very%20Best%20Of%20Stars%20On%2045%20%5BEdel%20Records%20-%200163732%20ERE%5D/large&path=%2Fmnt%2FUSB%2FMUSICS%2FStars%20On%2045%20-%20The%20Very%20Best%20Of%20Stars%20On%2045%20%5BEdel%20Records%20-%200163732%20ERE%5D%5BCD%2C%20Compilation%2C%20Germany%2C%202005%5D%5BFLAC%5D%2F06.%20Stars%20On%2045%20-%20Stars%20On%20Stevie%20(Original%2012-inch%20Version).flac&metadata=false Apr 20 08:34:22 volumio volumio[949]: info: URI /mnt/USB/MUSICS/Stars On 45 - The Very Best Of Stars On 45 [Edel Records - 0163732 ERE][CD, Compilation, Germany, 2005][FLAC]/06. Stars On 45 - Stars On Stevie (Original 12-inch Version).flac Apr 20 08:34:22 volumio volumio[949]: info: ALBUMART /albumart?cacheid=247&web=Stars%20On%2045/The%20Very%20Best%20Of%20Stars%20On%2045%20%5BEdel%20Records%20-%200163732%20ERE%5D/large&path=%2Fmnt%2FUSB%2FMUSICS%2FStars%20On%2045%20-%20The%20Very%20Best%20Of%20Stars%20On%2045%20%5BEdel%20Records%20-%200163732%20ERE%5D%5BCD%2C%20Compilation%2C%20Germany%2C%202005%5D%5BFLAC%5D%2F07.%20Stars%20On%2045%20-%20The%20Greatest%20Rock%20%26%20Roll%20Band%20In%20The%20World%20(Original%20Single%20Version).flac&metadata=false Apr 20 08:34:22 volumio volumio[949]: info: URI /mnt/USB/MUSICS/Stars On 45 - The Very Best Of Stars On 45 [Edel Records - 0163732 ERE][CD, Compilation, Germany, 2005][FLAC]/07. Stars On 45 - The Greatest Rock & Roll Band In The World (Original Single Version).flac Apr 20 08:34:22 volumio volumio[949]: info: ALBUMART /albumart?cacheid=247&web=Stars%20On%2045/The%20Very%20Best%20Of%20Stars%20On%2045%20%5BEdel%20Records%20-%200163732%20ERE%5D/large&path=%2Fmnt%2FUSB%2FMUSICS%2FStars%20On%2045%20-%20The%20Very%20Best%20Of%20Stars%20On%2045%20%5BEdel%20Records%20-%200163732%20ERE%5D%5BCD%2C%20Compilation%2C%20Germany%2C%202005%5D%5BFLAC%5D%2F08.%20Stars%20On%2045%20-%20The%20Beatles%20(Part%202)%20(Original%20Album%20Version).flac&metadata=false Apr 20 08:34:22 volumio volumio[949]: info: URI /mnt/USB/MUSICS/Stars On 45 - The Very Best Of Stars On 45 [Edel Records - 0163732 ERE][CD, Compilation, Germany, 2005][FLAC]/08. Stars On 45 - The Beatles (Part 2) (Original Album Version).flac Apr 20 08:34:22 volumio volumio[949]: info: ALBUMART /albumart?cacheid=247&web=Stars%20On%2045/The%20Very%20Best%20Of%20Stars%20On%2045%20%5BEdel%20Records%20-%200163732%20ERE%5D/large&path=%2Fmnt%2FUSB%2FMUSICS%2FStars%20On%2045%20-%20The%20Very%20Best%20Of%20Stars%20On%2045%20%5BEdel%20Records%20-%200163732%20ERE%5D%5BCD%2C%20Compilation%2C%20Germany%2C%202005%5D%5BFLAC%5D%2F09.%20Stars%20On%2045%20-%20The%20Beatles%20(George%20Harrison)%20(Original%20Album%20Version).flac&metadata=false Apr 20 08:34:22 volumio volumio[949]: info: URI /mnt/USB/MUSICS/Stars On 45 - The Very Best Of Stars On 45 [Edel Records - 0163732 ERE][CD, Compilation, Germany, 2005][FLAC]/09. Stars On 45 - The Beatles (George Harrison) (Original Album Version).flac Apr 20 08:34:22 volumio volumio[949]: info: ALBUMART /albumart?cacheid=247&web=Stars%20On%2045/The%20Very%20Best%20Of%20Stars%20On%2045%20%5BEdel%20Records%20-%200163732%20ERE%5D/large&path=%2Fmnt%2FUSB%2FMUSICS%2FStars%20On%2045%20-%20The%20Very%20Best%20Of%20Stars%20On%2045%20%5BEdel%20Records%20-%200163732%20ERE%5D%5BCD%2C%20Compilation%2C%20Germany%2C%202005%5D%5BFLAC%5D%2F10.%20Stars%20On%2045%20-%20The%20Supremes%20(Original%20Album%20Version).flac&metadata=false Apr 20 08:34:22 volumio volumio[949]: info: URI /mnt/USB/MUSICS/Stars On 45 - The Very Best Of Stars On 45 [Edel Records - 0163732 ERE][CD, Compilation, Germany, 2005][FLAC]/10. Stars On 45 - The Supremes (Original Album Version).flac Apr 20 08:34:22 volumio volumio[949]: info: ALBUMART /albumart?cacheid=247&web=Stars%20On%2045/The%20Very%20Best%20Of%20Stars%20On%2045%20%5BEdel%20Records%20-%200163732%20ERE%5D/large&path=%2Fmnt%2FUSB%2FMUSICS%2FStars%20On%2045%20-%20The%20Very%20Best%20Of%20Stars%20On%2045%20%5BEdel%20Records%20-%200163732%20ERE%5D%5BCD%2C%20Compilation%2C%20Germany%2C%202005%5D%5BFLAC%5D%2F11.%20Stars%20On%2045%20-%20Proudly%20Presents%20The%20Starsisters%20(Original%20Single%20Version).flac&metadata=false Apr 20 08:34:22 volumio volumio[949]: info: URI /mnt/USB/MUSICS/Stars On 45 - The Very Best Of Stars On 45 [Edel Records - 0163732 ERE][CD, Compilation, Germany, 2005][FLAC]/11. Stars On 45 - Proudly Presents The Starsisters (Original Single Version).flac Apr 20 08:34:22 volumio volumio[949]: info: ALBUMART /albumart?cacheid=247&web=Stars%20On%2045/The%20Very%20Best%20Of%20Stars%20On%2045%20%5BEdel%20Records%20-%200163732%20ERE%5D/large&path=%2Fmnt%2FUSB%2FMUSICS%2FStars%20On%2045%20-%20The%20Very%20Best%20Of%20Stars%20On%2045%20%5BEdel%20Records%20-%200163732%20ERE%5D%5BCD%2C%20Compilation%2C%20Germany%2C%202005%5D%5BFLAC%5D%2F12.%20Stars%20On%2045%20-%20Hooray%20For%20Hollywood%20(Original%20Single%20Version).flac&metadata=false Apr 20 08:34:22 volumio volumio[949]: info: URI /mnt/USB/MUSICS/Stars On 45 - The Very Best Of Stars On 45 [Edel Records - 0163732 ERE][CD, Compilation, Germany, 2005][FLAC]/12. Stars On 45 - Hooray For Hollywood (Original Single Version).flac Apr 20 08:34:22 volumio volumio[949]: info: ALBUMART /albumart?cacheid=247&web=Stars%20On%2045/The%20Very%20Best%20Of%20Stars%20On%2045%20%5BEdel%20Records%20-%200163732%20ERE%5D/large&path=%2Fmnt%2FUSB%2FMUSICS%2FStars%20On%2045%20-%20The%20Very%20Best%20Of%20Stars%20On%2045%20%5BEdel%20Records%20-%200163732%20ERE%5D%5BCD%2C%20Compilation%2C%20Germany%2C%202005%5D%5BFLAC%5D%2F13.%20Stars%20On%2045%20-%20A%20Tribute%20To%20Marlyn%20Monroe%20(Original%20Single%20Version).flac&metadata=false Apr 20 08:34:22 volumio volumio[949]: info: URI /mnt/USB/MUSICS/Stars On 45 - The Very Best Of Stars On 45 [Edel Records - 0163732 ERE][CD, Compilation, Germany, 2005][FLAC]/13. Stars On 45 - A Tribute To Marlyn Monroe (Original Single Version).flac Apr 20 08:34:22 volumio volumio[949]: info: CoreCommandRouter::volumioPushQueue Apr 20 08:34:22 volumio volumio[949]: info: CorePlayQueue::saveQueue Apr 20 08:34:22 volumio volumio[949]: info: CoreStateMachine::updateTrackBlock Apr 20 08:34:22 volumio volumio[949]: info: CorePlayQueue::getTrackBlock Apr 20 08:34:22 volumio volumio[949]: info: CoreCommandRouter::volumioPlay Apr 20 08:34:22 volumio volumio[949]: info: CoreStateMachine::play index 0 Apr 20 08:34:22 volumio volumio[949]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 20 08:34:22 volumio volumio[949]: info: CoreStateMachine::stop Apr 20 08:34:22 volumio volumio[949]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 20 08:34:22 volumio volumio[949]: info: CoreStateMachine::play index undefined Apr 20 08:34:22 volumio volumio[949]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 20 08:34:22 volumio volumio[949]: info: CorePlayQueue::getTrack 0 Apr 20 08:34:22 volumio volumio[949]: info: CoreStateMachine::startPlaybackTimer Apr 20 08:34:22 volumio volumio[949]: info: CorePlayQueue::getTrack 0 Apr 20 08:34:22 volumio volumio[949]: verbose: ControllerMpd::clearAddPlayTracks USB/MUSICS/Stars On 45 - The Very Best Of Stars On 45 [Edel Records - 0163732 ERE][CD, Compilation, Germany, 2005][FLAC]/01. Stars On 45 - Stars On 45 (Original Single Version).flac Apr 20 08:34:22 volumio volumio[949]: verbose: ControllerMpd::sendMpdCommand stop Apr 20 08:34:22 volumio volumio[949]: info: sendMpdCommand stop took 2 milliseconds Apr 20 08:34:22 volumio volumio[949]: verbose: ControllerMpd::sendMpdCommand clear Apr 20 08:34:22 volumio volumio[949]: info: Apr 20 08:34:22 volumio volumio[949]: ---------------------------- MPD announces system playlist update Apr 20 08:34:22 volumio volumio[949]: info: Ignoring MPD Status Update Apr 20 08:34:22 volumio volumio[949]: info: sendMpdCommand clear took 3 milliseconds Apr 20 08:34:22 volumio volumio[949]: verbose: ControllerMpd::sendMpdCommand add "USB/MUSICS/Stars On 45 - The Very Best Of Stars On 45 [Edel Records - 0163732 ERE][CD, Compilation, Germany, 2005][FLAC]/01. Stars On 45 - Stars On 45 (Original Single Version).flac" Apr 20 08:34:22 volumio volumio[949]: info: Apr 20 08:34:22 volumio volumio[949]: ---------------------------- MPD announces system playlist update Apr 20 08:34:22 volumio volumio[949]: info: Ignoring MPD Status Update Apr 20 08:34:22 volumio volumio[949]: info: Apr 20 08:34:22 volumio volumio[949]: ---------------------------- MPD announces system playlist update Apr 20 08:34:22 volumio volumio[949]: info: Ignoring MPD Status Update Apr 20 08:34:22 volumio volumio[949]: error: updateQueue error: null Apr 20 08:34:22 volumio volumio[949]: info: Apr 20 08:34:22 volumio volumio[949]: ---------------------------- MPD announces system playlist update Apr 20 08:34:22 volumio volumio[949]: info: Ignoring MPD Status Update Apr 20 08:34:22 volumio volumio[949]: info: ------------------------------ 10ms Apr 20 08:34:22 volumio volumio[949]: info: sendMpdCommand add "USB/MUSICS/Stars On 45 - The Very Best Of Stars On 45 [Edel Records - 0163732 ERE][CD, Compilation, Germany, 2005][FLAC]/01. Stars On 45 - Stars On 45 (Original Single Version).flac" took 8 milliseconds Apr 20 08:34:22 volumio volumio[949]: info: ------------------------------ 6ms Apr 20 08:34:22 volumio volumio[949]: info: ------------------------------ 4ms Apr 20 08:34:22 volumio volumio[949]: verbose: ControllerMpd::sendMpdCommand play Apr 20 08:34:22 volumio volumio[949]: info: Apr 20 08:34:22 volumio volumio[949]: ---------------------------- MPD announces system playlist update Apr 20 08:34:22 volumio volumio[949]: info: Ignoring MPD Status Update Apr 20 08:34:22 volumio volumio[949]: info: Apr 20 08:34:22 volumio volumio[949]: ---------------------------- MPD announces system playlist update Apr 20 08:34:22 volumio volumio[949]: info: Ignoring MPD Status Update Apr 20 08:34:22 volumio volumio[949]: info: ------------------------------ 14ms Apr 20 08:34:22 volumio volumio[949]: info: sendMpdCommand play took 11 milliseconds Apr 20 08:34:22 volumio volumio[949]: info: ------------------------------ 10ms Apr 20 08:34:22 volumio volumio[949]: info: ------------------------------ 9ms Apr 20 08:34:22 volumio volumio[949]: info: Apr 20 08:34:22 volumio volumio[949]: ---------------------------- MPD announces state update: player Apr 20 08:34:22 volumio volumio[949]: info: ControllerMpd::getState Apr 20 08:34:22 volumio volumio[949]: verbose: ControllerMpd::sendMpdCommand status Apr 20 08:34:22 volumio volumio[949]: info: Apr 20 08:34:22 volumio volumio[949]: ---------------------------- MPD announces state update: player Apr 20 08:34:22 volumio volumio[949]: info: ControllerMpd::getState Apr 20 08:34:22 volumio volumio[949]: verbose: ControllerMpd::sendMpdCommand status Apr 20 08:34:22 volumio volumio[949]: info: Apr 20 08:34:22 volumio volumio[949]: ---------------------------- MPD announces state update: player Apr 20 08:34:22 volumio volumio[949]: info: ControllerMpd::getState Apr 20 08:34:22 volumio kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Apr 20 08:34:22 volumio volumio[949]: verbose: ControllerMpd::sendMpdCommand status Apr 20 08:34:22 volumio volumio[949]: info: Apr 20 08:34:22 volumio volumio[949]: ---------------------------- MPD announces state update: player Apr 20 08:34:22 volumio volumio[949]: info: sendMpdCommand status took 17 milliseconds Apr 20 08:34:22 volumio volumio[949]: info: ControllerMpd::getState Apr 20 08:34:22 volumio volumio[949]: verbose: ControllerMpd::sendMpdCommand status Apr 20 08:34:22 volumio volumio[949]: verbose: ControllerMpd::parseState Apr 20 08:34:22 volumio volumio[949]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 20 08:34:22 volumio volumio[949]: info: sendMpdCommand status took 18 milliseconds Apr 20 08:34:22 volumio volumio[949]: info: sendMpdCommand status took 16 milliseconds Apr 20 08:34:22 volumio volumio[949]: verbose: ControllerMpd::parseState Apr 20 08:34:22 volumio volumio[949]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 20 08:34:22 volumio volumio[949]: verbose: ControllerMpd::parseState Apr 20 08:34:22 volumio volumio[949]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 20 08:34:22 volumio volumio[949]: info: Apr 20 08:34:22 volumio volumio[949]: ---------------------------- MPD announces state update: player Apr 20 08:34:22 volumio volumio[949]: info: ControllerMpd::getState Apr 20 08:34:22 volumio volumio[949]: verbose: ControllerMpd::sendMpdCommand status Apr 20 08:34:22 volumio volumio[949]: info: Apr 20 08:34:22 volumio volumio[949]: ---------------------------- MPD announces state update: player Apr 20 08:34:22 volumio volumio[949]: info: ControllerMpd::getState Apr 20 08:34:22 volumio volumio[949]: verbose: ControllerMpd::sendMpdCommand status Apr 20 08:34:22 volumio volumio[949]: info: sendMpdCommand status took 17 milliseconds Apr 20 08:34:22 volumio volumio[949]: info: sendMpdCommand playlistinfo took 17 milliseconds Apr 20 08:34:22 volumio volumio[949]: info: sendMpdCommand playlistinfo took 13 milliseconds Apr 20 08:34:22 volumio volumio[949]: info: sendMpdCommand playlistinfo took 13 milliseconds Apr 20 08:34:22 volumio volumio[949]: info: sendMpdCommand status took 11 milliseconds Apr 20 08:34:22 volumio volumio[949]: info: sendMpdCommand status took 9 milliseconds Apr 20 08:34:22 volumio volumio[949]: verbose: ControllerMpd::parseState Apr 20 08:34:22 volumio volumio[949]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 20 08:34:22 volumio volumio[949]: verbose: ControllerMpd::parseTrackInfo Apr 20 08:34:22 volumio volumio[949]: verbose: ControllerMpd::parseTrackInfo Apr 20 08:34:22 volumio volumio[949]: verbose: ControllerMpd::parseTrackInfo Apr 20 08:34:22 volumio volumio[949]: verbose: ControllerMpd::parseState Apr 20 08:34:22 volumio volumio[949]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 20 08:34:22 volumio volumio[949]: verbose: ControllerMpd::parseState Apr 20 08:34:22 volumio volumio[949]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 20 08:34:22 volumio volumio[949]: info: ControllerMpd::pushState Apr 20 08:34:22 volumio volumio[949]: info: CoreCommandRouter::servicePushState Apr 20 08:34:22 volumio volumio[949]: info: CorePlayQueue::getTrack 0 Apr 20 08:34:22 volumio volumio[949]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":287,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Stars On 45 (Original Single Version)","artist":"Stars On 45","album":"The Very Best Of Stars On 45 [Edel Records - 0163732 ERE]","uri":"USB/MUSICS/Stars On 45 - The Very Best Of Stars On 45 [Edel Records - 0163732 ERE][CD, Compilation, Germany, 2005][FLAC]/01. Stars On 45 - Stars On 45 (Original Single Version).flac","trackType":"flac"} Apr 20 08:34:22 volumio volumio[949]: verbose: CURRENT POSITION 0 Apr 20 08:34:22 volumio volumio[949]: info: CoreStateMachine::syncState stateService play Apr 20 08:34:22 volumio volumio[949]: info: CoreStateMachine::syncState currentStatus stop Apr 20 08:34:22 volumio volumio[949]: info: ControllerMpd::pushState Apr 20 08:34:22 volumio volumio[949]: info: CoreCommandRouter::servicePushState Apr 20 08:34:22 volumio volumio[949]: info: CorePlayQueue::getTrack 0 Apr 20 08:34:22 volumio volumio[949]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":287,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Stars On 45 (Original Single Version)","artist":"Stars On 45","album":"The Very Best Of Stars On 45 [Edel Records - 0163732 ERE]","uri":"USB/MUSICS/Stars On 45 - The Very Best Of Stars On 45 [Edel Records - 0163732 ERE][CD, Compilation, Germany, 2005][FLAC]/01. Stars On 45 - Stars On 45 (Original Single Version).flac","trackType":"flac"} Apr 20 08:34:22 volumio volumio[949]: verbose: CURRENT POSITION 0 Apr 20 08:34:22 volumio volumio[949]: info: CoreStateMachine::syncState stateService play Apr 20 08:34:22 volumio volumio[949]: info: CoreStateMachine::syncState currentStatus play Apr 20 08:34:22 volumio volumio[949]: info: Received an update from plugin. extracting info from payload Apr 20 08:34:22 volumio volumio[949]: info: CoreStateMachine::pushState Apr 20 08:34:22 volumio volumio[949]: info: CorePlayQueue::getTrack 0 Apr 20 08:34:22 volumio volumio[949]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 20 08:34:22 volumio volumio[949]: info: CoreCommandRouter::volumioPushState Apr 20 08:34:22 volumio volumio[949]: info: CoreStateMachine::pushState Apr 20 08:34:22 volumio volumio[949]: info: CorePlayQueue::getTrack 0 Apr 20 08:34:22 volumio volumio[949]: info: CoreCommandRouter::volumioPushState Apr 20 08:34:22 volumio volumio[949]: info: ControllerMpd::pushState Apr 20 08:34:22 volumio volumio[949]: info: CoreCommandRouter::servicePushState Apr 20 08:34:22 volumio volumio[949]: info: CorePlayQueue::getTrack 0 Apr 20 08:34:22 volumio volumio[949]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":287,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Stars On 45 (Original Single Version)","artist":"Stars On 45","album":"The Very Best Of Stars On 45 [Edel Records - 0163732 ERE]","uri":"USB/MUSICS/Stars On 45 - The Very Best Of Stars On 45 [Edel Records - 0163732 ERE][CD, Compilation, Germany, 2005][FLAC]/01. Stars On 45 - Stars On 45 (Original Single Version).flac","trackType":"flac"} Apr 20 08:34:22 volumio volumio[949]: verbose: CURRENT POSITION 0 Apr 20 08:34:22 volumio volumio[949]: info: CoreStateMachine::syncState stateService play Apr 20 08:34:22 volumio volumio[949]: info: CoreStateMachine::syncState currentStatus play Apr 20 08:34:22 volumio volumio[949]: info: Received an update from plugin. extracting info from payload Apr 20 08:34:22 volumio volumio[949]: info: CoreStateMachine::pushState Apr 20 08:34:22 volumio volumio[949]: info: CorePlayQueue::getTrack 0 Apr 20 08:34:22 volumio volumio[949]: info: CoreCommandRouter::volumioPushState Apr 20 08:34:22 volumio volumio[949]: info: CoreStateMachine::pushState Apr 20 08:34:22 volumio volumio[949]: info: CorePlayQueue::getTrack 0 Apr 20 08:34:22 volumio volumio[949]: info: CoreCommandRouter::volumioPushState Apr 20 08:34:22 volumio volumio[949]: info: ------------------------------ 66ms Apr 20 08:34:22 volumio volumio[949]: info: ------------------------------ 82ms Apr 20 08:34:22 volumio volumio[949]: info: ------------------------------ 81ms Apr 20 08:34:22 volumio volumio[949]: info: sendMpdCommand playlistinfo took 53 milliseconds Apr 20 08:34:22 volumio volumio[949]: info: sendMpdCommand playlistinfo took 52 milliseconds Apr 20 08:34:22 volumio volumio[949]: info: sendMpdCommand playlistinfo took 52 milliseconds Apr 20 08:34:22 volumio volumio[949]: verbose: ControllerMpd::parseTrackInfo Apr 20 08:34:22 volumio volumio[949]: verbose: ControllerMpd::parseTrackInfo Apr 20 08:34:22 volumio volumio[949]: verbose: ControllerMpd::parseTrackInfo Apr 20 08:34:22 volumio volumio[949]: info: ControllerMpd::pushState Apr 20 08:34:22 volumio volumio[949]: info: CoreCommandRouter::servicePushState Apr 20 08:34:22 volumio volumio[949]: info: CorePlayQueue::getTrack 0 Apr 20 08:34:22 volumio volumio[949]: verbose: STATE SERVICE {"status":"play","position":0,"seek":869,"duration":287,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"988 Kbps","isStreaming":false,"title":"Stars On 45 (Original Single Version)","artist":"Stars On 45","album":"The Very Best Of Stars On 45 [Edel Records - 0163732 ERE]","uri":"USB/MUSICS/Stars On 45 - The Very Best Of Stars On 45 [Edel Records - 0163732 ERE][CD, Compilation, Germany, 2005][FLAC]/01. Stars On 45 - Stars On 45 (Original Single Version).flac","trackType":"flac"} Apr 20 08:34:22 volumio volumio[949]: verbose: CURRENT POSITION 0 Apr 20 08:34:22 volumio volumio[949]: info: CoreStateMachine::syncState stateService play Apr 20 08:34:22 volumio volumio[949]: info: CoreStateMachine::syncState currentStatus play Apr 20 08:34:22 volumio volumio[949]: info: Received an update from plugin. extracting info from payload Apr 20 08:34:22 volumio volumio[949]: info: CoreStateMachine::pushState Apr 20 08:34:22 volumio volumio[949]: info: CorePlayQueue::getTrack 0 Apr 20 08:34:22 volumio volumio[949]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 20 08:34:22 volumio volumio[949]: info: CoreCommandRouter::volumioPushState Apr 20 08:34:22 volumio volumio[949]: info: CoreStateMachine::pushState Apr 20 08:34:22 volumio volumio[949]: info: CorePlayQueue::getTrack 0 Apr 20 08:34:22 volumio volumio[949]: info: CoreCommandRouter::volumioPushState Apr 20 08:34:22 volumio volumio[949]: info: ControllerMpd::pushState Apr 20 08:34:22 volumio volumio[949]: info: CoreCommandRouter::servicePushState Apr 20 08:34:22 volumio volumio[949]: info: CorePlayQueue::getTrack 0 Apr 20 08:34:22 volumio volumio[949]: verbose: STATE SERVICE {"status":"play","position":0,"seek":869,"duration":287,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"981 Kbps","isStreaming":false,"title":"Stars On 45 (Original Single Version)","artist":"Stars On 45","album":"The Very Best Of Stars On 45 [Edel Records - 0163732 ERE]","uri":"USB/MUSICS/Stars On 45 - The Very Best Of Stars On 45 [Edel Records - 0163732 ERE][CD, Compilation, Germany, 2005][FLAC]/01. Stars On 45 - Stars On 45 (Original Single Version).flac","trackType":"flac"} Apr 20 08:34:22 volumio volumio[949]: verbose: CURRENT POSITION 0 Apr 20 08:34:22 volumio volumio[949]: info: CoreStateMachine::syncState stateService play Apr 20 08:34:22 volumio volumio[949]: info: CoreStateMachine::syncState currentStatus play Apr 20 08:34:22 volumio volumio[949]: info: Received an update from plugin. extracting info from payload Apr 20 08:34:22 volumio volumio[949]: info: CoreStateMachine::pushState Apr 20 08:34:22 volumio volumio[949]: info: CorePlayQueue::getTrack 0 Apr 20 08:34:22 volumio volumio[949]: info: CoreCommandRouter::volumioPushState Apr 20 08:34:22 volumio volumio[949]: info: CoreStateMachine::pushState Apr 20 08:34:22 volumio volumio[949]: info: CorePlayQueue::getTrack 0 Apr 20 08:34:22 volumio volumio[949]: info: CoreCommandRouter::volumioPushState Apr 20 08:34:22 volumio volumio[949]: info: ControllerMpd::pushState Apr 20 08:34:22 volumio volumio[949]: info: CoreCommandRouter::servicePushState Apr 20 08:34:22 volumio volumio[949]: info: CorePlayQueue::getTrack 0 Apr 20 08:34:22 volumio volumio[949]: verbose: STATE SERVICE {"status":"play","position":0,"seek":869,"duration":287,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"975 Kbps","isStreaming":false,"title":"Stars On 45 (Original Single Version)","artist":"Stars On 45","album":"The Very Best Of Stars On 45 [Edel Records - 0163732 ERE]","uri":"USB/MUSICS/Stars On 45 - The Very Best Of Stars On 45 [Edel Records - 0163732 ERE][CD, Compilation, Germany, 2005][FLAC]/01. Stars On 45 - Stars On 45 (Original Single Version).flac","trackType":"flac"} Apr 20 08:34:22 volumio volumio[949]: verbose: CURRENT POSITION 0 Apr 20 08:34:22 volumio volumio[949]: info: CoreStateMachine::syncState stateService play Apr 20 08:34:22 volumio volumio[949]: info: CoreStateMachine::syncState currentStatus play Apr 20 08:34:22 volumio volumio[949]: info: Received an update from plugin. extracting info from payload Apr 20 08:34:22 volumio volumio[949]: info: CoreStateMachine::pushState Apr 20 08:34:22 volumio volumio[949]: info: CorePlayQueue::getTrack 0 Apr 20 08:34:22 volumio volumio[949]: info: CoreCommandRouter::volumioPushState Apr 20 08:34:22 volumio volumio[949]: info: CoreStateMachine::pushState Apr 20 08:34:22 volumio volumio[949]: info: CorePlayQueue::getTrack 0 Apr 20 08:34:22 volumio volumio[949]: info: CoreCommandRouter::volumioPushState Apr 20 08:34:22 volumio volumio[949]: info: ------------------------------ 105ms Apr 20 08:34:22 volumio volumio[949]: info: ------------------------------ 98ms Apr 20 08:34:22 volumio volumio[949]: info: ------------------------------ 97ms Apr 20 08:34:22 volumio volumio[949]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Apr 20 08:34:22 volumio volumio[949]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Apr 20 08:34:22 volumio volumio[949]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Apr 20 08:34:22 volumio volumio[949]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Apr 20 08:34:22 volumio volumio[949]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Apr 20 08:34:22 volumio volumio[949]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Apr 20 08:34:22 volumio volumio[949]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Apr 20 08:34:22 volumio volumio[949]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Apr 20 08:34:22 volumio volumio[949]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Apr 20 08:34:22 volumio volumio[949]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Apr 20 08:34:24 volumio volumio[949]: info: Initializing connection to go-librespot Websocket Apr 20 08:34:24 volumio volumio[949]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 20 08:34:25 volumio volumio[949]: info: Preload queue cleared Apr 20 08:34:25 volumio volumio[949]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 20 08:34:25 volumio volumio[949]: info: CoreStateMachine::ClearQueue Apr 20 08:34:25 volumio volumio[949]: info: CoreStateMachine::stop Apr 20 08:34:25 volumio volumio[949]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 20 08:34:25 volumio volumio[949]: info: CoreStateMachine::stPlaybackTimer Apr 20 08:34:25 volumio volumio[949]: info: CoreStateMachine::updateTrackBlock Apr 20 08:34:25 volumio volumio[949]: info: CorePlayQueue::getTrackBlock Apr 20 08:34:25 volumio volumio[949]: info: CoreStateMachine::pushState Apr 20 08:34:25 volumio volumio[949]: info: CorePlayQueue::getTrack 0 Apr 20 08:34:25 volumio volumio[949]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 20 08:34:25 volumio volumio[949]: info: CoreCommandRouter::volumioPushState Apr 20 08:34:25 volumio volumio[949]: info: CoreStateMachine::serviceStop Apr 20 08:34:25 volumio volumio[949]: info: CorePlayQueue::getTrack 0 Apr 20 08:34:25 volumio volumio[949]: info: CoreCommandRouter::serviceStop Apr 20 08:34:25 volumio volumio[949]: info: ControllerMpd::stop Apr 20 08:34:25 volumio volumio[949]: verbose: ControllerMpd::sendMpdCommand stop Apr 20 08:34:25 volumio volumio[949]: info: CorePlayQueue::clearPlayQueue Apr 20 08:34:25 volumio volumio[949]: info: CorePlayQueue::saveQueue Apr 20 08:34:25 volumio volumio[949]: info: CoreCommandRouter::volumioPushQueue Apr 20 08:34:25 volumio volumio[949]: info: CoreStateMachine::addQueueItems Apr 20 08:34:25 volumio volumio[949]: info: CorePlayQueue::addQueueItems Apr 20 08:34:25 volumio volumio[949]: info: Preload queue cleared Apr 20 08:34:25 volumio volumio[949]: info: Adding Item to queue: music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition) Apr 20 08:34:25 volumio volumio[949]: info: Exploding uri music-library/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition) in service mpd Apr 20 08:34:25 volumio volumio[949]: info: Apr 20 08:34:25 volumio volumio[949]: ---------------------------- MPD announces state update: player Apr 20 08:34:25 volumio volumio[949]: info: ALBUMART /albumart?cacheid=247&web=Surface/Surface/large&path=%2Fmnt%2FUSB%2FMUSICS%2FSurface%20-%201987%20-%20Surface%20(Expanded%20Edition)%2F01.%20Let%E2%80%99s%20Try%20Again.flac&metadata=false Apr 20 08:34:25 volumio volumio[949]: info: URI /mnt/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/01. Let’s Try Again.flac Apr 20 08:34:25 volumio volumio[949]: info: ALBUMART /albumart?cacheid=247&web=Surface/Surface/large&path=%2Fmnt%2FUSB%2FMUSICS%2FSurface%20-%201987%20-%20Surface%20(Expanded%20Edition)%2F02.%20Happy.flac&metadata=false Apr 20 08:34:25 volumio volumio[949]: info: URI /mnt/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/02. Happy.flac Apr 20 08:34:25 volumio volumio[949]: info: ALBUMART /albumart?cacheid=247&web=Surface/Surface/large&path=%2Fmnt%2FUSB%2FMUSICS%2FSurface%20-%201987%20-%20Surface%20(Expanded%20Edition)%2F03.%20We%E2%80%99re%20All%20Searchin%E2%80%99.flac&metadata=false Apr 20 08:34:25 volumio volumio[949]: info: URI /mnt/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/03. We’re All Searchin’.flac Apr 20 08:34:25 volumio volumio[949]: info: ALBUMART /albumart?cacheid=247&web=Surface/Surface/large&path=%2Fmnt%2FUSB%2FMUSICS%2FSurface%20-%201987%20-%20Surface%20(Expanded%20Edition)%2F04.%20Lately.flac&metadata=false Apr 20 08:34:25 volumio volumio[949]: info: URI /mnt/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/04. Lately.flac Apr 20 08:34:25 volumio volumio[949]: info: ALBUMART /albumart?cacheid=247&web=Surface/Surface/large&path=%2Fmnt%2FUSB%2FMUSICS%2FSurface%20-%201987%20-%20Surface%20(Expanded%20Edition)%2F05.%20Gotta%20Make%20Love%20Tonight.flac&metadata=false Apr 20 08:34:25 volumio volumio[949]: info: URI /mnt/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/05. Gotta Make Love Tonight.flac Apr 20 08:34:25 volumio volumio[949]: info: ALBUMART /albumart?cacheid=247&web=Surface/Surface/large&path=%2Fmnt%2FUSB%2FMUSICS%2FSurface%20-%201987%20-%20Surface%20(Expanded%20Edition)%2F06.%20Who%20Loves%20You.flac&metadata=false Apr 20 08:34:25 volumio volumio[949]: info: URI /mnt/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/06. Who Loves You.flac Apr 20 08:34:25 volumio volumio[949]: info: ALBUMART /albumart?cacheid=247&web=Surface/Surface/large&path=%2Fmnt%2FUSB%2FMUSICS%2FSurface%20-%201987%20-%20Surface%20(Expanded%20Edition)%2F07.%20You%E2%80%99re%20Fine.flac&metadata=false Apr 20 08:34:25 volumio volumio[949]: info: URI /mnt/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/07. You’re Fine.flac Apr 20 08:34:25 volumio volumio[949]: info: ALBUMART /albumart?cacheid=247&web=Surface/Surface/large&path=%2Fmnt%2FUSB%2FMUSICS%2FSurface%20-%201987%20-%20Surface%20(Expanded%20Edition)%2F08.%20Lady%20Wants%20a%20Man.flac&metadata=false Apr 20 08:34:25 volumio volumio[949]: info: URI /mnt/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/08. Lady Wants a Man.flac Apr 20 08:34:25 volumio volumio[949]: info: ALBUMART /albumart?cacheid=247&web=Surface/Surface/large&path=%2Fmnt%2FUSB%2FMUSICS%2FSurface%20-%201987%20-%20Surface%20(Expanded%20Edition)%2F09.%20Girls%20Were%20Made%20to%20Love.flac&metadata=false Apr 20 08:34:25 volumio volumio[949]: info: URI /mnt/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/09. Girls Were Made to Love.flac Apr 20 08:34:25 volumio volumio[949]: info: ALBUMART /albumart?cacheid=247&web=Surface/Surface/large&path=%2Fmnt%2FUSB%2FMUSICS%2FSurface%20-%201987%20-%20Surface%20(Expanded%20Edition)%2F10.%20Feels%20So%20Good.flac&metadata=false Apr 20 08:34:25 volumio volumio[949]: info: URI /mnt/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/10. Feels So Good.flac Apr 20 08:34:25 volumio volumio[949]: info: ALBUMART /albumart?cacheid=247&web=Surface/Surface/large&path=%2Fmnt%2FUSB%2FMUSICS%2FSurface%20-%201987%20-%20Surface%20(Expanded%20Edition)%2F11.%20Happy%20(Love%20mix).flac&metadata=false Apr 20 08:34:25 volumio volumio[949]: info: URI /mnt/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/11. Happy (Love mix).flac Apr 20 08:34:25 volumio volumio[949]: info: ALBUMART /albumart?cacheid=247&web=Surface/Surface/large&path=%2Fmnt%2FUSB%2FMUSICS%2FSurface%20-%201987%20-%20Surface%20(Expanded%20Edition)%2F12.%20Happy%20(12_%20remix).flac&metadata=false Apr 20 08:34:25 volumio volumio[949]: info: URI /mnt/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/12. Happy (12_ remix).flac Apr 20 08:34:25 volumio volumio[949]: info: ALBUMART /albumart?cacheid=247&web=Surface/Surface/large&path=%2Fmnt%2FUSB%2FMUSICS%2FSurface%20-%201987%20-%20Surface%20(Expanded%20Edition)%2F13.%20Happy%20(12_%20remix%20_%20instrumental).flac&metadata=false Apr 20 08:34:25 volumio volumio[949]: info: URI /mnt/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/13. Happy (12_ remix _ instrumental).flac Apr 20 08:34:25 volumio volumio[949]: info: ALBUMART /albumart?cacheid=247&web=Surface/Surface/large&path=%2Fmnt%2FUSB%2FMUSICS%2FSurface%20-%201987%20-%20Surface%20(Expanded%20Edition)%2F14.%20Happy%20(extended%20version).flac&metadata=false Apr 20 08:34:25 volumio volumio[949]: info: URI /mnt/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/14. Happy (extended version).flac Apr 20 08:34:25 volumio volumio[949]: info: ALBUMART /albumart?cacheid=247&web=Surface/Surface/large&path=%2Fmnt%2FUSB%2FMUSICS%2FSurface%20-%201987%20-%20Surface%20(Expanded%20Edition)%2F15.%20Let%E2%80%99s%20Try%20Again%20(extended%20version).flac&metadata=false Apr 20 08:34:25 volumio volumio[949]: info: URI /mnt/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/15. Let’s Try Again (extended version).flac Apr 20 08:34:25 volumio volumio[949]: info: ALBUMART /albumart?cacheid=247&web=Surface/Surface/large&path=%2Fmnt%2FUSB%2FMUSICS%2FSurface%20-%201987%20-%20Surface%20(Expanded%20Edition)%2F16.%20Let%E2%80%99s%20Try%20Again%20(instrumental%20version).flac&metadata=false Apr 20 08:34:25 volumio volumio[949]: info: URI /mnt/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/16. Let’s Try Again (instrumental version).flac Apr 20 08:34:25 volumio volumio[949]: info: ALBUMART /albumart?cacheid=247&web=Surface/Surface/large&path=%2Fmnt%2FUSB%2FMUSICS%2FSurface%20-%201987%20-%20Surface%20(Expanded%20Edition)%2F17.%20Lately%20(12_%20mix).flac&metadata=false Apr 20 08:34:25 volumio volumio[949]: info: URI /mnt/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/17. Lately (12_ mix).flac Apr 20 08:34:25 volumio volumio[949]: info: ALBUMART /albumart?cacheid=247&web=Surface/Surface/large&path=%2Fmnt%2FUSB%2FMUSICS%2FSurface%20-%201987%20-%20Surface%20(Expanded%20Edition)%2FSurface%20-%20Surface.cue&metadata=false Apr 20 08:34:25 volumio volumio[949]: info: URI /mnt/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/Surface - Surface.cue Apr 20 08:34:25 volumio volumio[949]: info: ALBUMART /albumart?cacheid=247&web=Surface/Surface/large&path=%2Fmnt%2FUSB%2FMUSICS%2FSurface%20-%201987%20-%20Surface%20(Expanded%20Edition)%2FSurface%20-%20Surface.cue&metadata=false Apr 20 08:34:25 volumio volumio[949]: info: URI /mnt/USB/MUSICS/Surface - 1987 - Surface (Expanded Edition)/Surface - Surface.cue Apr 20 08:34:25 volumio volumio[949]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 20 08:34:25 volumio volumio[949]: Error: Unable to resolve or reject the same promise twice Apr 20 08:34:25 volumio volumio[949]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Apr 20 08:34:25 volumio volumio[949]: at /volumio/app/plugins/music_service/mpd/index.js:2568:21 Apr 20 08:34:25 volumio volumio[949]: at MpdClient.handleMessage (/volumio/app/plugins/music_service/mpd/lib/mpd.js:77:3) Apr 20 08:34:25 volumio volumio[949]: at MpdClient.receive (/volumio/app/plugins/music_service/mpd/lib/mpd.js:68:12) Apr 20 08:34:25 volumio volumio[949]: at Socket. (/volumio/app/plugins/music_service/mpd/lib/mpd.js:43:12) Apr 20 08:34:25 volumio volumio[949]: at Socket.emit (events.js:315:20) Apr 20 08:34:25 volumio volumio[949]: at addChunk (internal/streams/readable.js:309:12) Apr 20 08:34:25 volumio volumio[949]: at readableAddChunk (internal/streams/readable.js:280:11) Apr 20 08:34:25 volumio volumio[949]: at Socket.Readable.push (internal/streams/readable.js:223:10) Apr 20 08:34:25 volumio volumio[949]: at Pipe.onStreamRead (internal/stream_base_commons.js:188:23) Apr 20 08:34:25 volumio volumio[949]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 20 08:34:25 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 20 08:34:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2321. Apr 20 08:34:25 volumio systemd[1]: Stopped go-librespot Daemon. Apr 20 08:34:25 volumio systemd[1]: Started go-librespot Daemon. Apr 20 08:34:25 volumio go-librespot[7282]: Librespot-go daemon starting... Apr 20 08:34:25 volumio go-librespot[7282]: time="2024-04-20T08:34:25Z" level=info msg="generated new device id: c3c12dd13d8022c46b42146b40aede18e0bbce73" Apr 20 08:34:25 volumio go-librespot[7282]: time="2024-04-20T08:34:25Z" level=debug msg="stored credentials found for vloo68" Apr 20 08:34:25 volumio sudo[7290]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-04-20 08:33 Apr 20 08:34:25 volumio sudo[7290]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 20 08:34:25 volumio go-librespot[7282]: time="2024-04-20T08:34:25Z" level=debug msg="obtained new client token: AABpP9d/hD7T72Tr0l6KM8l/dQaIP2dRWbi/LhxDe2BV5ABHGvEmFBqHjgxnY44jCeeEYlnsGrB6SgP2GYaQO6zXp2u8zkygWbo9eu+QRiaPop2/iGJIPMZlllTSuvqpY9JkbwwGefd0cg5ui7srxYumBD8vg0u9ro/1LxeJgV8B+Ij/5ECuq5vPWkaH8gaR34oBQavEbVQ/3mAJ1GvLBkVOOmX5hljsQ8CnElB2CrmIbqA8P3nrlweThITJLVc=" Apr 20 08:34:25 volumio go-librespot[7282]: time="2024-04-20T08:34:25Z" 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]" 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="7f9f1bf001add7a8b19a4516e3c74ef598b2730d" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="512433c3e91cdaed7ecd2808b21adeffc2137d7f" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 21 Feb 2024 09:37:22 PM CET" VOLUMIO_VERSION="3.631" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fdd9dd1169c06c1ad0a30ddd24c91b6b"