-- Logs begin at Fri 2025-03-14 11:39:04 CET, end at Fri 2025-03-14 14:21:56 CET. -- Mar 14 14:20:00 volumio go-librespot[2816]: time="2025-03-14T14:20:00+01:00" level=debug msg="completed challenge" Mar 14 14:20:00 volumio go-librespot[2816]: time="2025-03-14T14:20:00+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 14 14:20:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 14 14:20:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 14 14:20:00 volumio volumio[838]: info: Initializing connection to go-librespot Websocket Mar 14 14:20:00 volumio volumio[838]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 14 14:20:02 volumio wpa_supplicant[754]: wlan0: Failed to initiate sched scan Mar 14 14:20:03 volumio volumio[838]: info: Initializing connection to go-librespot Websocket Mar 14 14:20:03 volumio volumio[838]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 14 14:20:03 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 14 14:20:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31554. Mar 14 14:20:03 volumio systemd[1]: Stopped go-librespot Daemon. Mar 14 14:20:03 volumio systemd[1]: Started go-librespot Daemon. Mar 14 14:20:03 volumio go-librespot[2825]: Librespot-go daemon starting... Mar 14 14:20:03 volumio go-librespot[2825]: time="2025-03-14T14:20:03+01:00" level=info msg="generated new device id: 7635ecbeea3e18c8eae73d66a8d033cf86fc9c08" Mar 14 14:20:03 volumio go-librespot[2825]: time="2025-03-14T14:20:03+01:00" level=debug msg="stored credentials found for fone129" Mar 14 14:20:04 volumio go-librespot[2825]: time="2025-03-14T14:20:04+01:00" level=debug msg="obtained new client token: AAA9EfA+20cnQ8b3ebcjiCAIXxSd5D7rAi+nS3deIsAeWpRek8eWjjYwjIw49hg5n4mrRqflP9rBz7vhsauYlTp+GlsIE03tetXDCvW7P8iRFiBoydDILyQLaUAIvRJeJtNxBeUQa74tvLD2k/filWrPCc0mo148cDvAzTqyMTGMZrvpIVzdTyTm0T78TFgc6nstEwSFHrJUr8Zl7XBMmLKTxUNGaeVE5kWucfZ4UYfHjSne8swnA9St1Ig=" Mar 14 14:20:04 volumio go-librespot[2825]: time="2025-03-14T14:20:04+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 14 14:20:04 volumio go-librespot[2825]: time="2025-03-14T14:20:04+01:00" level=debug msg="completed keyexchange" Mar 14 14:20:04 volumio go-librespot[2825]: time="2025-03-14T14:20:04+01:00" level=debug msg="completed challenge" Mar 14 14:20:04 volumio go-librespot[2825]: time="2025-03-14T14:20:04+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 14 14:20:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 14 14:20:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 14 14:20:06 volumio volumio[838]: info: Initializing connection to go-librespot Websocket Mar 14 14:20:06 volumio volumio[838]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 14 14:20:07 volumio wpa_supplicant[754]: wlan0: Failed to initiate sched scan Mar 14 14:20:08 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 14 14:20:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31555. Mar 14 14:20:08 volumio systemd[1]: Stopped go-librespot Daemon. Mar 14 14:20:08 volumio systemd[1]: Started go-librespot Daemon. Mar 14 14:20:08 volumio go-librespot[2833]: Librespot-go daemon starting... Mar 14 14:20:08 volumio go-librespot[2833]: time="2025-03-14T14:20:08+01:00" level=info msg="generated new device id: 18e09fa8bed3345c0ca6dceda9db91d95edc0975" Mar 14 14:20:08 volumio go-librespot[2833]: time="2025-03-14T14:20:08+01:00" level=debug msg="stored credentials found for fone129" Mar 14 14:20:08 volumio go-librespot[2833]: time="2025-03-14T14:20:08+01:00" level=debug msg="obtained new client token: AABnJRlWP363TwABqtKdSzftuXr7h0PCf+B7h+iLZl7DtmJeObP7uZ9Kxp8xTTCj8wHkTO4nwp+MTTDv0EmGZuc9pH9Cy3a6+KjcbiWXq6kvTEjCtL1xe9qqge+CanRpxKnM3b4OA8+hVm7D3VwfPyhOjmF3GGdur1jha+BVwmHQ+v78dPjDx/qDY98AvJt56lt1hmtcnfMglC84FeLy1InwrY/yxfg0VvtdFfPj02UCIsjTLz9TAzoZ0V8=" Mar 14 14:20:08 volumio go-librespot[2833]: time="2025-03-14T14:20:08+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 14 14:20:08 volumio go-librespot[2833]: time="2025-03-14T14:20:08+01:00" level=debug msg="completed keyexchange" Mar 14 14:20:09 volumio go-librespot[2833]: time="2025-03-14T14:20:09+01:00" level=debug msg="completed challenge" Mar 14 14:20:09 volumio go-librespot[2833]: time="2025-03-14T14:20:09+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 14 14:20:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 14 14:20:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 14 14:20:09 volumio volumio[838]: info: Initializing connection to go-librespot Websocket Mar 14 14:20:09 volumio volumio[838]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 14 14:20:12 volumio volumio[838]: info: Initializing connection to go-librespot Websocket Mar 14 14:20:12 volumio volumio[838]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 14 14:20:12 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 14 14:20:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31556. Mar 14 14:20:12 volumio systemd[1]: Stopped go-librespot Daemon. Mar 14 14:20:12 volumio systemd[1]: Started go-librespot Daemon. Mar 14 14:20:12 volumio go-librespot[2841]: Librespot-go daemon starting... Mar 14 14:20:12 volumio go-librespot[2841]: time="2025-03-14T14:20:12+01:00" level=info msg="generated new device id: 776479d39c9374ce2f6607beb8420f6c7304995d" Mar 14 14:20:12 volumio go-librespot[2841]: time="2025-03-14T14:20:12+01:00" level=debug msg="stored credentials found for fone129" Mar 14 14:20:13 volumio go-librespot[2841]: time="2025-03-14T14:20:13+01:00" level=debug msg="obtained new client token: AADt1LTbfq98HKI2ccvK0DkAOZyVOlU5+noNrvoLDleruk2LXWxrQjoKKQ8AQ4DCOI7FerTyhrPIjheRqcCPL6xLQIN867f7I04OOBzEYV/ovyqrpKEYSYaVfi2cqr/2NaA1t+MrY28iPhURZnPVW1bBkZsr9xcFsYam5EymBYT8bG84Lxv2QjEE9O5hVri6LJWP6kpZQeMZMTg0BkJrQG5h5KaeoTnWfdtuB6TYSfkab9BnJa9So43t" Mar 14 14:20:13 volumio wpa_supplicant[754]: wlan0: Failed to initiate sched scan Mar 14 14:20:13 volumio go-librespot[2841]: time="2025-03-14T14:20:13+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 14 14:20:13 volumio go-librespot[2841]: time="2025-03-14T14:20:13+01:00" level=debug msg="completed keyexchange" Mar 14 14:20:14 volumio go-librespot[2841]: time="2025-03-14T14:20:14+01:00" level=debug msg="completed challenge" Mar 14 14:20:14 volumio go-librespot[2841]: time="2025-03-14T14:20:14+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 14 14:20:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 14 14:20:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 14 14:20:15 volumio volumio[838]: info: Initializing connection to go-librespot Websocket Mar 14 14:20:15 volumio volumio[838]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 14 14:20:17 volumio volumio[838]: STREAMING PROXY: Handling url / Mar 14 14:20:17 volumio volumio[838]: info: No valid Plugin REST Endpoint Mar 14 14:20:17 volumio volumio[838]: STREAMING PROXY: Error: Failed to retrieve proper real streamUrl Mar 14 14:20:17 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 14 14:20:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31557. Mar 14 14:20:17 volumio systemd[1]: Stopped go-librespot Daemon. Mar 14 14:20:17 volumio systemd[1]: Started go-librespot Daemon. Mar 14 14:20:17 volumio go-librespot[2849]: Librespot-go daemon starting... Mar 14 14:20:17 volumio go-librespot[2849]: time="2025-03-14T14:20:17+01:00" level=info msg="generated new device id: 35bb1c22297d91a39f7ca23d5b29e60e670322a1" Mar 14 14:20:17 volumio go-librespot[2849]: time="2025-03-14T14:20:17+01:00" level=debug msg="stored credentials found for fone129" Mar 14 14:20:17 volumio go-librespot[2849]: time="2025-03-14T14:20:17+01:00" level=debug msg="obtained new client token: AABjvzUGYATJr5wEwPC2brnIw/uXpI4+hOHDq5VdsNXSvDx9e1HsT4Fzt3DbGMiMLn5xc6qqbcdk8rfFQjIxngzYhlstjaQ3eY2HX66aoAMgYFVrVG7JtWHtVIahcp3oKfqVwIjYFAqf4LWTWW6BcTWFsfcwKk5GR3Z5a621O/rcoFqIyyipfiyaeB3YmsZPxX8mShgjwkJHGqlQAUZCGwvKBlCiYc7YINWZWxRUJhJhv/cbjq3yXLTQ51w=" Mar 14 14:20:17 volumio go-librespot[2849]: time="2025-03-14T14:20:17+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 14 14:20:17 volumio go-librespot[2849]: time="2025-03-14T14:20:17+01:00" level=debug msg="completed keyexchange" Mar 14 14:20:18 volumio go-librespot[2849]: time="2025-03-14T14:20:18+01:00" level=debug msg="completed challenge" Mar 14 14:20:18 volumio go-librespot[2849]: time="2025-03-14T14:20:18+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 14 14:20:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 14 14:20:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 14 14:20:18 volumio volumio[838]: info: Initializing connection to go-librespot Websocket Mar 14 14:20:18 volumio volumio[838]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 14 14:20:18 volumio wpa_supplicant[754]: wlan0: Failed to initiate sched scan Mar 14 14:20:21 volumio volumio[838]: info: Initializing connection to go-librespot Websocket Mar 14 14:20:21 volumio volumio[838]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 14 14:20:21 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 14 14:20:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31558. Mar 14 14:20:21 volumio systemd[1]: Stopped go-librespot Daemon. Mar 14 14:20:21 volumio systemd[1]: Started go-librespot Daemon. Mar 14 14:20:21 volumio go-librespot[2857]: Librespot-go daemon starting... Mar 14 14:20:21 volumio go-librespot[2857]: time="2025-03-14T14:20:21+01:00" level=info msg="generated new device id: d3cae94d363312a72e1f5135f86adc7ac1db5c39" Mar 14 14:20:21 volumio go-librespot[2857]: time="2025-03-14T14:20:21+01:00" level=debug msg="stored credentials found for fone129" Mar 14 14:20:22 volumio go-librespot[2857]: time="2025-03-14T14:20:22+01:00" level=debug msg="obtained new client token: AAC8G5n1XBwhLteZDBw5B5WGfsGGP/uHW0jHe7ev5E5daTZEm82bIq/INYmYQrDcJSB5fu5DkFCJLII4+eHeqjEgACSPVx00n85FsRBySHKRsSbKo/uC+pagX02+KMPSGzd48qNkAOfp6jZIvAnfWxsTw03e3ypHjO4804DHQzCknP3uw/tUmrk8tC6ZVKvuMG6/Hj1KCWWyfbw/bqaLpZwj8YASHcJfDB4HSh8SCFLTfwojWoMgtFq2LCE=" Mar 14 14:20:22 volumio volumio[838]: STREAMING PROXY: Handling url / Mar 14 14:20:22 volumio volumio[838]: info: No valid Plugin REST Endpoint Mar 14 14:20:22 volumio volumio[838]: STREAMING PROXY: Error: Failed to retrieve proper real streamUrl Mar 14 14:20:22 volumio go-librespot[2857]: time="2025-03-14T14:20:22+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 14 14:20:22 volumio go-librespot[2857]: time="2025-03-14T14:20:22+01:00" level=debug msg="completed keyexchange" Mar 14 14:20:22 volumio go-librespot[2857]: time="2025-03-14T14:20:22+01:00" level=debug msg="completed challenge" Mar 14 14:20:22 volumio go-librespot[2857]: time="2025-03-14T14:20:22+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 14 14:20:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 14 14:20:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 14 14:20:23 volumio volumio[838]: STREAMING PROXY: Handling url / Mar 14 14:20:23 volumio volumio[838]: info: No valid Plugin REST Endpoint Mar 14 14:20:23 volumio volumio[838]: STREAMING PROXY: Error: Failed to retrieve proper real streamUrl Mar 14 14:20:24 volumio wpa_supplicant[754]: wlan0: Failed to initiate sched scan Mar 14 14:20:24 volumio volumio[838]: info: Initializing connection to go-librespot Websocket Mar 14 14:20:24 volumio volumio[838]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 14 14:20:26 volumio volumio[838]: STREAMING PROXY: Handling url / Mar 14 14:20:26 volumio volumio[838]: info: No valid Plugin REST Endpoint Mar 14 14:20:26 volumio volumio[838]: STREAMING PROXY: Error: Failed to retrieve proper real streamUrl Mar 14 14:20:26 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 14 14:20:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31559. Mar 14 14:20:26 volumio systemd[1]: Stopped go-librespot Daemon. Mar 14 14:20:26 volumio systemd[1]: Started go-librespot Daemon. Mar 14 14:20:26 volumio go-librespot[2865]: Librespot-go daemon starting... Mar 14 14:20:26 volumio go-librespot[2865]: time="2025-03-14T14:20:26+01:00" level=info msg="generated new device id: 62e82ca6d9e7a197c17cbb8f665ad5ea0a969318" Mar 14 14:20:26 volumio go-librespot[2865]: time="2025-03-14T14:20:26+01:00" level=debug msg="stored credentials found for fone129" Mar 14 14:20:26 volumio go-librespot[2865]: time="2025-03-14T14:20:26+01:00" level=debug msg="obtained new client token: AADvfFgt26C80sguUfBsurKKuBckiB93TlLT9/9sbCTSkyr5Arj/uE8TwDYhKZ6cLkDzBvyQOTLqrxQB546s0zZG8l8M0772QlO6r+/qvdJjoQ3GMpiyGYp/LbFz2WJnRHsPODeJgg5s5uT/linwDLoGuebeRGngupbXQYFDxyfjynH94f7LjOSgPaZne9X17UtqePdBZQUT9tPF4LKov2l8t5vzUvVpZYIM5i8xIiQBRhU4RLAUJL9i+XY=" Mar 14 14:20:26 volumio go-librespot[2865]: time="2025-03-14T14:20:26+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 14 14:20:26 volumio go-librespot[2865]: time="2025-03-14T14:20:26+01:00" level=debug msg="completed keyexchange" Mar 14 14:20:27 volumio go-librespot[2865]: time="2025-03-14T14:20:27+01:00" level=debug msg="completed challenge" Mar 14 14:20:27 volumio go-librespot[2865]: time="2025-03-14T14:20:27+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 14 14:20:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 14 14:20:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 14 14:20:27 volumio volumio[838]: info: Initializing connection to go-librespot Websocket Mar 14 14:20:27 volumio volumio[838]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 14 14:20:27 volumio volumio[838]: info: Mar 14 14:20:27 volumio volumio[838]: ---------------------------- MPD announces system playlist update Mar 14 14:20:27 volumio volumio[838]: info: Ignoring MPD Status Update Mar 14 14:20:27 volumio volumio[838]: info: Mar 14 14:20:27 volumio volumio[838]: ---------------------------- MPD announces state update: player Mar 14 14:20:27 volumio volumio[838]: info: ControllerMpd::getState Mar 14 14:20:27 volumio volumio[838]: verbose: ControllerMpd::sendMpdCommand status Mar 14 14:20:27 volumio volumio[838]: info: ------------------------------ 3ms Mar 14 14:20:27 volumio volumio[838]: info: sendMpdCommand status took 2 milliseconds Mar 14 14:20:27 volumio volumio[838]: verbose: ControllerMpd::parseState Mar 14 14:20:27 volumio volumio[838]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 14 14:20:27 volumio volumio[838]: info: sendMpdCommand playlistinfo took 0 milliseconds Mar 14 14:20:27 volumio volumio[838]: verbose: ControllerMpd::parseTrackInfo Mar 14 14:20:27 volumio volumio[838]: info: ControllerMpd::pushState Mar 14 14:20:27 volumio volumio[838]: info: CoreCommandRouter::servicePushState Mar 14 14:20:27 volumio volumio[838]: info: CorePlayQueue::getTrack 0 Mar 14 14:20:27 volumio volumio[838]: verbose: STATE SERVICE {"status":"play","position":0,"seek":28226978,"duration":0,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"124 Kbps","isStreaming":false,"title":"Pan Savyan & Julia Kamińska - Bursztynowe koraliki","artist":"Radio 357","album":null,"uri":"https://stream.rcs.revma.com/ye5kghkgcm0uv","trackType":""} Mar 14 14:20:27 volumio volumio[838]: verbose: CURRENT POSITION 0 Mar 14 14:20:27 volumio volumio[838]: info: CoreStateMachine::syncState stateService play Mar 14 14:20:27 volumio volumio[838]: info: CoreStateMachine::syncState currentStatus play Mar 14 14:20:27 volumio volumio[838]: info: Received an update from plugin. extracting info from payload Mar 14 14:20:27 volumio volumio[838]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Mar 14 14:20:27 volumio volumio[838]: info: CoreStateMachine::pushState Mar 14 14:20:27 volumio volumio[838]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 14 14:20:27 volumio volumio[838]: info: CoreCommandRouter::volumioPushState Mar 14 14:20:27 volumio volumio[838]: info: CoreStateMachine::pushState Mar 14 14:20:27 volumio volumio[838]: info: CoreCommandRouter::volumioPushState Mar 14 14:20:27 volumio volumio[838]: info: ------------------------------ 16ms Mar 14 14:20:27 volumio volumio[838]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Mar 14 14:20:27 volumio volumio[838]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Mar 14 14:20:28 volumio volumio[838]: STREAMING PROXY: Handling url / Mar 14 14:20:28 volumio volumio[838]: info: No valid Plugin REST Endpoint Mar 14 14:20:28 volumio volumio[838]: STREAMING PROXY: Error: Failed to retrieve proper real streamUrl Mar 14 14:20:28 volumio volumio[838]: STREAMING PROXY: Handling url / Mar 14 14:20:28 volumio volumio[838]: info: No valid Plugin REST Endpoint Mar 14 14:20:28 volumio volumio[838]: STREAMING PROXY: Error: Failed to retrieve proper real streamUrl Mar 14 14:20:29 volumio wpa_supplicant[754]: wlan0: Failed to initiate sched scan Mar 14 14:20:30 volumio volumio[838]: info: Initializing connection to go-librespot Websocket Mar 14 14:20:30 volumio volumio[838]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 14 14:20:30 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 14 14:20:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31560. Mar 14 14:20:30 volumio systemd[1]: Stopped go-librespot Daemon. Mar 14 14:20:30 volumio systemd[1]: Started go-librespot Daemon. Mar 14 14:20:30 volumio go-librespot[2873]: Librespot-go daemon starting... Mar 14 14:20:30 volumio go-librespot[2873]: time="2025-03-14T14:20:30+01:00" level=info msg="generated new device id: b6c4b30105247eff655a247895184cd0f0ad5a81" Mar 14 14:20:30 volumio go-librespot[2873]: time="2025-03-14T14:20:30+01:00" level=debug msg="stored credentials found for fone129" Mar 14 14:20:31 volumio go-librespot[2873]: time="2025-03-14T14:20:31+01:00" level=debug msg="obtained new client token: AABJdlXoaJ2zZdUUB1171CVwVuGkHL45BrT9jcaqeLLRKAOZIPYi2zwWY8YPvSuzXZ59mMkJfZu84W/1/IGoIkjXNambwCpnz+gwulvuTCc66FU4dCGpVnPiib+wu1p3reLxVKadItd9axCQqJvQuzw8UMTihykRt4KvaIYeqZV8KEUYlBVT5sVON7tUSSdjTC43koOk8Qw41W56YFLs69PXObgf6LgnUgb4yabQgX6sfs3wlqW9r/LA" Mar 14 14:20:31 volumio volumio[838]: STREAMING PROXY: Handling url / Mar 14 14:20:31 volumio volumio[838]: info: No valid Plugin REST Endpoint Mar 14 14:20:31 volumio volumio[838]: STREAMING PROXY: Error: Failed to retrieve proper real streamUrl Mar 14 14:20:31 volumio go-librespot[2873]: time="2025-03-14T14:20:31+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 14 14:20:32 volumio go-librespot[2873]: time="2025-03-14T14:20:32+01:00" level=debug msg="completed keyexchange" Mar 14 14:20:32 volumio go-librespot[2873]: time="2025-03-14T14:20:32+01:00" level=debug msg="completed challenge" Mar 14 14:20:32 volumio go-librespot[2873]: time="2025-03-14T14:20:32+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 14 14:20:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 14 14:20:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 14 14:20:33 volumio volumio[838]: info: Initializing connection to go-librespot Websocket Mar 14 14:20:33 volumio volumio[838]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 14 14:20:35 volumio wpa_supplicant[754]: wlan0: Failed to initiate sched scan Mar 14 14:20:35 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 14 14:20:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31561. Mar 14 14:20:35 volumio systemd[1]: Stopped go-librespot Daemon. Mar 14 14:20:35 volumio systemd[1]: Started go-librespot Daemon. Mar 14 14:20:35 volumio go-librespot[2881]: Librespot-go daemon starting... Mar 14 14:20:35 volumio go-librespot[2881]: time="2025-03-14T14:20:35+01:00" level=info msg="generated new device id: 5bfc23d107351e314602bd176a1e025af798be69" Mar 14 14:20:35 volumio go-librespot[2881]: time="2025-03-14T14:20:35+01:00" level=debug msg="stored credentials found for fone129" Mar 14 14:20:36 volumio go-librespot[2881]: time="2025-03-14T14:20:36+01:00" level=debug msg="obtained new client token: AABCWMDS6Qd6NTO88fdn1CB1xdgbwvgDlDIR5n8EtOkARW0zV/U7wSyFYlVkntF62KJuKsxqkutWsAzLSmhVKvmptZj0hjJ7Zr3f85LjQE2PrL2l7VCVZd+HunXYj2+jY8AEgGCFPxCfRBAbw1ghd/RUDTiERZqfBO/Ns1WYfqxKvfvUZh1yNL8IDRGC/zmk9v3Ax6GYeKh31HDCZaDujoiwQ0pmCmnmvMNXdaWuhHRThqomEjfoWAFt" Mar 14 14:20:36 volumio volumio[838]: STREAMING PROXY: Handling url / Mar 14 14:20:36 volumio go-librespot[2881]: time="2025-03-14T14:20:36+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 14 14:20:36 volumio volumio[838]: info: No valid Plugin REST Endpoint Mar 14 14:20:36 volumio volumio[838]: STREAMING PROXY: Error: Failed to retrieve proper real streamUrl Mar 14 14:20:36 volumio volumio[838]: info: Initializing connection to go-librespot Websocket Mar 14 14:20:36 volumio go-librespot[2881]: time="2025-03-14T14:20:36+01:00" level=debug msg="new websocket client" Mar 14 14:20:36 volumio volumio[838]: info: Connection to go-librespot Websocket established Mar 14 14:20:36 volumio go-librespot[2881]: time="2025-03-14T14:20:36+01:00" level=debug msg="completed keyexchange" Mar 14 14:20:37 volumio go-librespot[2881]: time="2025-03-14T14:20:37+01:00" level=debug msg="completed challenge" Mar 14 14:20:37 volumio go-librespot[2881]: time="2025-03-14T14:20:37+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 14 14:20:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 14 14:20:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 14 14:20:37 volumio volumio[838]: info: Connection to go-librespot Websocket closed Mar 14 14:20:39 volumio volumio[838]: info: Getting Spotify volume Mar 14 14:20:39 volumio volumio[838]: (node:838) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 14 14:20:39 volumio volumio[838]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 14 14:20:39 volumio volumio[838]: (node:838) 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: 6242) Mar 14 14:20:39 volumio volumio[838]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 Mar 14 14:20:39 volumio volumio[838]: info: CoreCommandRouter::volumioGetState Mar 14 14:20:39 volumio volumio[838]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Mar 14 14:20:40 volumio volumio[838]: info: Initializing connection to go-librespot Websocket Mar 14 14:20:40 volumio volumio[838]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 14 14:20:40 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 14 14:20:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31562. Mar 14 14:20:40 volumio systemd[1]: Stopped go-librespot Daemon. Mar 14 14:20:40 volumio systemd[1]: Started go-librespot Daemon. Mar 14 14:20:40 volumio go-librespot[2889]: Librespot-go daemon starting... Mar 14 14:20:40 volumio go-librespot[2889]: time="2025-03-14T14:20:40+01:00" level=info msg="generated new device id: c0e6a825e2c116cd5f4a346f1fa5f7e8a35673c3" Mar 14 14:20:40 volumio go-librespot[2889]: time="2025-03-14T14:20:40+01:00" level=debug msg="stored credentials found for fone129" Mar 14 14:20:40 volumio wpa_supplicant[754]: wlan0: Failed to initiate sched scan Mar 14 14:20:41 volumio go-librespot[2889]: time="2025-03-14T14:20:41+01:00" level=debug msg="obtained new client token: AADxKISQZvcuN4fAzgCsUe9K+UValLgxZRMr3dOZ1mm2mImxsuE8PUAZwda9KU78AsnkuOJdrBxirZZfI1xZmnbphoburXERbNeErxbSAnkYY1EM3BVNtlwNdsZO4VeFyvouJEEamR7K3ym6uGWH+fThrOy2svoWl1JkfN+7bSVBagfwzgYuIxVJUXg3Fm5nZ1hybCcJfoaUjPqbRaD6Gth2yNOoAZW94s+ZaHRmY2eJxJvb83HJsxuABko=" Mar 14 14:20:41 volumio go-librespot[2889]: time="2025-03-14T14:20:41+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 14 14:20:41 volumio go-librespot[2889]: time="2025-03-14T14:20:41+01:00" level=debug msg="completed keyexchange" Mar 14 14:20:42 volumio go-librespot[2889]: time="2025-03-14T14:20:42+01:00" level=debug msg="completed challenge" Mar 14 14:20:42 volumio go-librespot[2889]: time="2025-03-14T14:20:42+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 14 14:20:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 14 14:20:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 14 14:20:43 volumio volumio[838]: info: Initializing connection to go-librespot Websocket Mar 14 14:20:43 volumio volumio[838]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 14 14:20:44 volumio volumio[838]: STREAMING PROXY: Handling url / Mar 14 14:20:44 volumio volumio[838]: info: No valid Plugin REST Endpoint Mar 14 14:20:44 volumio volumio[838]: STREAMING PROXY: Error: Failed to retrieve proper real streamUrl Mar 14 14:20:45 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 14 14:20:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31563. Mar 14 14:20:45 volumio systemd[1]: Stopped go-librespot Daemon. Mar 14 14:20:45 volumio systemd[1]: Started go-librespot Daemon. Mar 14 14:20:45 volumio go-librespot[2898]: Librespot-go daemon starting... Mar 14 14:20:45 volumio go-librespot[2898]: time="2025-03-14T14:20:45+01:00" level=info msg="generated new device id: 8572bdaaf5784d4488b3df23d75210d35b4237e5" Mar 14 14:20:45 volumio go-librespot[2898]: time="2025-03-14T14:20:45+01:00" level=debug msg="stored credentials found for fone129" Mar 14 14:20:46 volumio go-librespot[2898]: time="2025-03-14T14:20:46+01:00" level=debug msg="obtained new client token: AADh54c7WYQ2qqHOSfEMR5T2kLVCS3G/BmM4ZEnTSopVdy/4/m8i77Ry17t2Vbdme2z+nP3rkKSY1Sc7jbQJB6vGtqQsQ5N+KqDHFr0i+o6vUEE/fLfyC1iJjnCm/LmeBceZ1qGEm74OWekQ5rAqEdijjd61q1zg2wMzWabH14dHxxAGK9WHTKshECcREcSOeuPkej2fl652nav69qKZYxfj1ddjfkE9AZgGOP6+Jsyh+w9KKHQsWY4CTGI=" Mar 14 14:20:46 volumio go-librespot[2898]: time="2025-03-14T14:20:46+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 14 14:20:46 volumio volumio[838]: info: Initializing connection to go-librespot Websocket Mar 14 14:20:46 volumio go-librespot[2898]: time="2025-03-14T14:20:46+01:00" level=debug msg="new websocket client" Mar 14 14:20:46 volumio volumio[838]: info: Connection to go-librespot Websocket established Mar 14 14:20:46 volumio wpa_supplicant[754]: wlan0: Failed to initiate sched scan Mar 14 14:20:46 volumio go-librespot[2898]: time="2025-03-14T14:20:46+01:00" level=debug msg="completed keyexchange" Mar 14 14:20:46 volumio go-librespot[2898]: time="2025-03-14T14:20:46+01:00" level=debug msg="completed challenge" Mar 14 14:20:46 volumio go-librespot[2898]: time="2025-03-14T14:20:46+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 14 14:20:46 volumio volumio[838]: info: Connection to go-librespot Websocket closed Mar 14 14:20:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 14 14:20:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 14 14:20:49 volumio volumio[838]: info: Getting Spotify volume Mar 14 14:20:49 volumio volumio[838]: (node:838) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 14 14:20:49 volumio volumio[838]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 14 14:20:49 volumio volumio[838]: (node:838) 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: 6243) Mar 14 14:20:49 volumio volumio[838]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 Mar 14 14:20:49 volumio volumio[838]: info: CoreCommandRouter::volumioGetState Mar 14 14:20:49 volumio volumio[838]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Mar 14 14:20:49 volumio volumio[838]: info: Initializing connection to go-librespot Websocket Mar 14 14:20:49 volumio volumio[838]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 14 14:20:50 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 14 14:20:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31564. Mar 14 14:20:50 volumio systemd[1]: Stopped go-librespot Daemon. Mar 14 14:20:50 volumio systemd[1]: Started go-librespot Daemon. Mar 14 14:20:50 volumio go-librespot[2906]: Librespot-go daemon starting... Mar 14 14:20:50 volumio go-librespot[2906]: time="2025-03-14T14:20:50+01:00" level=info msg="generated new device id: 9f541385a9abecca6b28d8641c326104ca7738bc" Mar 14 14:20:50 volumio go-librespot[2906]: time="2025-03-14T14:20:50+01:00" level=debug msg="stored credentials found for fone129" Mar 14 14:20:50 volumio go-librespot[2906]: time="2025-03-14T14:20:50+01:00" level=debug msg="obtained new client token: AADkLtsEAtHw5LLLhDGTphxv8584ydA+y1pyEE35NlvvdtLzZZ4jsXMz9uWh3nyDIiXabDFuHbStxRPOGCMYO30Zf3NuZdrU6thUWckEh0CrfKoN5YdohVXMUle6DWyelTUkXurmy1UprkVGwNIowlVL6HpeuEL2UT25ipv0ScpWbupdPqynksqJQmIss2ozpD3CmBD/zvgkRZFMExTfNZgm/A/4r7GsFt5Txe3fDqpkbo1EZryH4V69ZJ0=" Mar 14 14:20:51 volumio go-librespot[2906]: time="2025-03-14T14:20:51+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 14 14:20:51 volumio go-librespot[2906]: time="2025-03-14T14:20:51+01:00" level=debug msg="completed keyexchange" Mar 14 14:20:51 volumio go-librespot[2906]: time="2025-03-14T14:20:51+01:00" level=debug msg="completed challenge" Mar 14 14:20:51 volumio go-librespot[2906]: time="2025-03-14T14:20:51+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 14 14:20:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 14 14:20:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 14 14:20:51 volumio wpa_supplicant[754]: wlan0: Failed to initiate sched scan Mar 14 14:20:52 volumio volumio[838]: info: Initializing connection to go-librespot Websocket Mar 14 14:20:52 volumio volumio[838]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 14 14:20:54 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 14 14:20:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31565. Mar 14 14:20:54 volumio systemd[1]: Stopped go-librespot Daemon. Mar 14 14:20:54 volumio systemd[1]: Started go-librespot Daemon. Mar 14 14:20:54 volumio go-librespot[2914]: Librespot-go daemon starting... Mar 14 14:20:54 volumio go-librespot[2914]: time="2025-03-14T14:20:54+01:00" level=info msg="generated new device id: 6c7a6660f9eb3c6cc201fa29df41b8dae5de03d7" Mar 14 14:20:54 volumio go-librespot[2914]: time="2025-03-14T14:20:54+01:00" level=debug msg="stored credentials found for fone129" Mar 14 14:20:55 volumio go-librespot[2914]: time="2025-03-14T14:20:55+01:00" level=debug msg="obtained new client token: AADAfhoOKWbqIGvmIcL6Ij6tVpdSiJi4IBoGpVRRK+/KsKPB873q3L8ersnTorlWsXhwHCDDp2z8lZBBazAgj6rBA89STbgArFp/yJq2TcWYOz2DVMPt0R2Zu5RZL1srOynyMSHJv69vTsV4akaMDTPzT/EQT0t7WA+9vtA5rZXcVxhq81kjBxivuv1j/Y0NiC1GnAXDrpD+QeZ6QQJhwJKw5VUWsrIw9Xc9NfQACVCojDVb80yhGlgyk9w=" Mar 14 14:20:55 volumio volumio[838]: info: Initializing connection to go-librespot Websocket Mar 14 14:20:56 volumio go-librespot[2914]: time="2025-03-14T14:20:56+01:00" level=debug msg="new websocket client" Mar 14 14:20:56 volumio volumio[838]: info: Connection to go-librespot Websocket established Mar 14 14:20:56 volumio go-librespot[2914]: time="2025-03-14T14:20:56+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 14 14:20:56 volumio go-librespot[2914]: time="2025-03-14T14:20:56+01:00" level=debug msg="completed keyexchange" Mar 14 14:20:56 volumio volumio[838]: STREAMING PROXY: Handling url /Wsusadmin/Errors/BrowserSettings.aspx Mar 14 14:20:56 volumio volumio[838]: info: No valid Plugin REST Endpoint Mar 14 14:20:56 volumio volumio[838]: STREAMING PROXY: Error: Failed to retrieve proper real streamUrl Mar 14 14:20:56 volumio volumio[838]: STREAMING PROXY: Handling url / Mar 14 14:20:56 volumio volumio[838]: info: No valid Plugin REST Endpoint Mar 14 14:20:56 volumio volumio[838]: STREAMING PROXY: Error: Failed to retrieve proper real streamUrl Mar 14 14:20:56 volumio go-librespot[2914]: time="2025-03-14T14:20:56+01:00" level=debug msg="completed challenge" Mar 14 14:20:56 volumio go-librespot[2914]: time="2025-03-14T14:20:56+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 14 14:20:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 14 14:20:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 14 14:20:56 volumio volumio[838]: info: Connection to go-librespot Websocket closed Mar 14 14:20:57 volumio wpa_supplicant[754]: wlan0: Failed to initiate sched scan Mar 14 14:20:59 volumio volumio[838]: info: Getting Spotify volume Mar 14 14:20:59 volumio volumio[838]: (node:838) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 14 14:20:59 volumio volumio[838]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 14 14:20:59 volumio volumio[838]: (node:838) 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: 6244) Mar 14 14:20:59 volumio volumio[838]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 Mar 14 14:20:59 volumio volumio[838]: info: CoreCommandRouter::volumioGetState Mar 14 14:20:59 volumio volumio[838]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Mar 14 14:20:59 volumio volumio[838]: info: Initializing connection to go-librespot Websocket Mar 14 14:20:59 volumio volumio[838]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 14 14:21:00 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 14 14:21:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31566. Mar 14 14:21:00 volumio systemd[1]: Stopped go-librespot Daemon. Mar 14 14:21:00 volumio systemd[1]: Started go-librespot Daemon. Mar 14 14:21:00 volumio go-librespot[2923]: Librespot-go daemon starting... Mar 14 14:21:00 volumio go-librespot[2923]: time="2025-03-14T14:21:00+01:00" level=info msg="generated new device id: 52b64133b0ee41c68bc8672e4af60827fa26298b" Mar 14 14:21:00 volumio go-librespot[2923]: time="2025-03-14T14:21:00+01:00" level=debug msg="stored credentials found for fone129" Mar 14 14:21:00 volumio go-librespot[2923]: time="2025-03-14T14:21:00+01:00" level=debug msg="obtained new client token: AABjUDqi2YGkqDCwe/IXma1lK6CDGKo1RN9L325WvQY3LyI2WlAt1quFgyY94iDhABZvFbBMOXnVPnEPBSxJX2TvsDT10D75sZf16HGWdLRlqgxonEVdx3vzI4M9XmnLHqtIPFImlsM3u/0cuMk/t+b/GBmdSlVgk6Pf9HFvxjnlIYlY6gH7qEjBXOiAgUL+kHzycsZLVi8skgyKten+rrjryyL69WmB0Bp/++xLp20moB+A2nSZBfpajB4=" Mar 14 14:21:00 volumio go-librespot[2923]: time="2025-03-14T14:21:00+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 14 14:21:01 volumio volumio[838]: URIError: Failed to decode param '%80../%80../%80../%80../%80../%80../windows/win.ini' Mar 14 14:21:01 volumio volumio[838]: at decodeURIComponent () Mar 14 14:21:01 volumio volumio[838]: at decode_param (/volumio/node_modules/express/lib/router/layer.js:172:12) Mar 14 14:21:01 volumio volumio[838]: at Layer.match (/volumio/node_modules/express/lib/router/layer.js:148:15) Mar 14 14:21:01 volumio volumio[838]: at matchLayer (/volumio/node_modules/express/lib/router/index.js:574:18) Mar 14 14:21:01 volumio volumio[838]: at next (/volumio/node_modules/express/lib/router/index.js:220:15) Mar 14 14:21:01 volumio volumio[838]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:91:12) Mar 14 14:21:01 volumio volumio[838]: at trim_prefix (/volumio/node_modules/express/lib/router/index.js:317:13) Mar 14 14:21:01 volumio volumio[838]: at /volumio/node_modules/express/lib/router/index.js:284:7 Mar 14 14:21:01 volumio volumio[838]: at Function.process_params (/volumio/node_modules/express/lib/router/index.js:335:12) Mar 14 14:21:01 volumio volumio[838]: at next (/volumio/node_modules/express/lib/router/index.js:275:10) Mar 14 14:21:01 volumio volumio[838]: URIError: Failed to decode param '%80../%80../%80../%80../%80../%80../winnt/win.ini' Mar 14 14:21:01 volumio volumio[838]: at decodeURIComponent () Mar 14 14:21:01 volumio volumio[838]: at decode_param (/volumio/node_modules/express/lib/router/layer.js:172:12) Mar 14 14:21:01 volumio volumio[838]: at Layer.match (/volumio/node_modules/express/lib/router/layer.js:148:15) Mar 14 14:21:01 volumio volumio[838]: at matchLayer (/volumio/node_modules/express/lib/router/index.js:574:18) Mar 14 14:21:01 volumio volumio[838]: at next (/volumio/node_modules/express/lib/router/index.js:220:15) Mar 14 14:21:01 volumio volumio[838]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:91:12) Mar 14 14:21:01 volumio volumio[838]: at trim_prefix (/volumio/node_modules/express/lib/router/index.js:317:13) Mar 14 14:21:01 volumio volumio[838]: at /volumio/node_modules/express/lib/router/index.js:284:7 Mar 14 14:21:01 volumio volumio[838]: at Function.process_params (/volumio/node_modules/express/lib/router/index.js:335:12) Mar 14 14:21:01 volumio volumio[838]: at next (/volumio/node_modules/express/lib/router/index.js:275:10) Mar 14 14:21:01 volumio volumio[838]: URIError: Failed to decode param '%c0.%c0./%c0.%c0./%c0.%c0./%c0.%c0./%c0.%c0./windows/win.ini' Mar 14 14:21:01 volumio volumio[838]: at decodeURIComponent () Mar 14 14:21:01 volumio volumio[838]: at decode_param (/volumio/node_modules/express/lib/router/layer.js:172:12) Mar 14 14:21:01 volumio volumio[838]: at Layer.match (/volumio/node_modules/express/lib/router/layer.js:148:15) Mar 14 14:21:01 volumio volumio[838]: at matchLayer (/volumio/node_modules/express/lib/router/index.js:574:18) Mar 14 14:21:01 volumio volumio[838]: at next (/volumio/node_modules/express/lib/router/index.js:220:15) Mar 14 14:21:01 volumio volumio[838]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:91:12) Mar 14 14:21:01 volumio volumio[838]: at trim_prefix (/volumio/node_modules/express/lib/router/index.js:317:13) Mar 14 14:21:01 volumio volumio[838]: at /volumio/node_modules/express/lib/router/index.js:284:7 Mar 14 14:21:01 volumio volumio[838]: at Function.process_params (/volumio/node_modules/express/lib/router/index.js:335:12) Mar 14 14:21:01 volumio volumio[838]: at next (/volumio/node_modules/express/lib/router/index.js:275:10) Mar 14 14:21:01 volumio volumio[838]: URIError: Failed to decode param '%c0.%c0./%c0.%c0./%c0.%c0./%c0.%c0./%c0.%c0./winnt/win.ini' Mar 14 14:21:01 volumio volumio[838]: at decodeURIComponent () Mar 14 14:21:01 volumio volumio[838]: at decode_param (/volumio/node_modules/express/lib/router/layer.js:172:12) Mar 14 14:21:01 volumio volumio[838]: at Layer.match (/volumio/node_modules/express/lib/router/layer.js:148:15) Mar 14 14:21:01 volumio volumio[838]: at matchLayer (/volumio/node_modules/express/lib/router/index.js:574:18) Mar 14 14:21:01 volumio volumio[838]: at next (/volumio/node_modules/express/lib/router/index.js:220:15) Mar 14 14:21:01 volumio volumio[838]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:91:12) Mar 14 14:21:01 volumio volumio[838]: at trim_prefix (/volumio/node_modules/express/lib/router/index.js:317:13) Mar 14 14:21:01 volumio volumio[838]: at /volumio/node_modules/express/lib/router/index.js:284:7 Mar 14 14:21:01 volumio volumio[838]: at Function.process_params (/volumio/node_modules/express/lib/router/index.js:335:12) Mar 14 14:21:01 volumio volumio[838]: at next (/volumio/node_modules/express/lib/router/index.js:275:10) Mar 14 14:21:01 volumio volumio[838]: URIError: Failed to decode param '%c0%2e%c0%2e/%c0%2e%c0%2e/%c0%2e%c0%2e/%c0%2e%c0%2e/windows/win.ini' Mar 14 14:21:01 volumio volumio[838]: at decodeURIComponent () Mar 14 14:21:01 volumio volumio[838]: at decode_param (/volumio/node_modules/express/lib/router/layer.js:172:12) Mar 14 14:21:01 volumio volumio[838]: at Layer.match (/volumio/node_modules/express/lib/router/layer.js:148:15) Mar 14 14:21:01 volumio volumio[838]: at matchLayer (/volumio/node_modules/express/lib/router/index.js:574:18) Mar 14 14:21:01 volumio volumio[838]: at next (/volumio/node_modules/express/lib/router/index.js:220:15) Mar 14 14:21:01 volumio volumio[838]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:91:12) Mar 14 14:21:01 volumio volumio[838]: at trim_prefix (/volumio/node_modules/express/lib/router/index.js:317:13) Mar 14 14:21:01 volumio volumio[838]: at /volumio/node_modules/express/lib/router/index.js:284:7 Mar 14 14:21:01 volumio volumio[838]: at Function.process_params (/volumio/node_modules/express/lib/router/index.js:335:12) Mar 14 14:21:01 volumio volumio[838]: at next (/volumio/node_modules/express/lib/router/index.js:275:10) Mar 14 14:21:01 volumio volumio[838]: URIError: Failed to decode param '%c0%2e%c0%2e/%c0%2e%c0%2e/%c0%2e%c0%2e/%c0%2e%c0%2e/winnt/win.ini' Mar 14 14:21:01 volumio volumio[838]: at decodeURIComponent () Mar 14 14:21:01 volumio volumio[838]: at decode_param (/volumio/node_modules/express/lib/router/layer.js:172:12) Mar 14 14:21:01 volumio volumio[838]: at Layer.match (/volumio/node_modules/express/lib/router/layer.js:148:15) Mar 14 14:21:01 volumio volumio[838]: at matchLayer (/volumio/node_modules/express/lib/router/index.js:574:18) Mar 14 14:21:01 volumio volumio[838]: at next (/volumio/node_modules/express/lib/router/index.js:220:15) Mar 14 14:21:01 volumio volumio[838]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:91:12) Mar 14 14:21:01 volumio volumio[838]: at trim_prefix (/volumio/node_modules/express/lib/router/index.js:317:13) Mar 14 14:21:01 volumio volumio[838]: at /volumio/node_modules/express/lib/router/index.js:284:7 Mar 14 14:21:01 volumio volumio[838]: at Function.process_params (/volumio/node_modules/express/lib/router/index.js:335:12) Mar 14 14:21:01 volumio volumio[838]: at next (/volumio/node_modules/express/lib/router/index.js:275:10) Mar 14 14:21:01 volumio volumio[838]: URIError: Failed to decode param '%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/windows/win.ini' Mar 14 14:21:01 volumio volumio[838]: at decodeURIComponent () Mar 14 14:21:01 volumio volumio[838]: at decode_param (/volumio/node_modules/express/lib/router/layer.js:172:12) Mar 14 14:21:01 volumio volumio[838]: at Layer.match (/volumio/node_modules/express/lib/router/layer.js:148:15) Mar 14 14:21:01 volumio volumio[838]: at matchLayer (/volumio/node_modules/express/lib/router/index.js:574:18) Mar 14 14:21:01 volumio volumio[838]: at next (/volumio/node_modules/express/lib/router/index.js:220:15) Mar 14 14:21:01 volumio volumio[838]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:91:12) Mar 14 14:21:01 volumio volumio[838]: at trim_prefix (/volumio/node_modules/express/lib/router/index.js:317:13) Mar 14 14:21:01 volumio volumio[838]: at /volumio/node_modules/express/lib/router/index.js:284:7 Mar 14 14:21:01 volumio volumio[838]: at Function.process_params (/volumio/node_modules/express/lib/router/index.js:335:12) Mar 14 14:21:01 volumio volumio[838]: at next (/volumio/node_modules/express/lib/router/index.js:275:10) Mar 14 14:21:01 volumio volumio[838]: URIError: Failed to decode param '%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/winnt/win.ini' Mar 14 14:21:01 volumio volumio[838]: at decodeURIComponent () Mar 14 14:21:01 volumio volumio[838]: at decode_param (/volumio/node_modules/express/lib/router/layer.js:172:12) Mar 14 14:21:01 volumio volumio[838]: at Layer.match (/volumio/node_modules/express/lib/router/layer.js:148:15) Mar 14 14:21:01 volumio volumio[838]: at matchLayer (/volumio/node_modules/express/lib/router/index.js:574:18) Mar 14 14:21:01 volumio volumio[838]: at next (/volumio/node_modules/express/lib/router/index.js:220:15) Mar 14 14:21:01 volumio volumio[838]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:91:12) Mar 14 14:21:01 volumio volumio[838]: at trim_prefix (/volumio/node_modules/express/lib/router/index.js:317:13) Mar 14 14:21:01 volumio volumio[838]: at /volumio/node_modules/express/lib/router/index.js:284:7 Mar 14 14:21:01 volumio volumio[838]: at Function.process_params (/volumio/node_modules/express/lib/router/index.js:335:12) Mar 14 14:21:01 volumio volumio[838]: at next (/volumio/node_modules/express/lib/router/index.js:275:10) Mar 14 14:21:01 volumio go-librespot[2923]: time="2025-03-14T14:21:01+01:00" level=debug msg="completed keyexchange" Mar 14 14:21:01 volumio volumio[838]: URIError: Failed to decode param '%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/etc/passwd' Mar 14 14:21:01 volumio volumio[838]: at decodeURIComponent () Mar 14 14:21:01 volumio volumio[838]: at decode_param (/volumio/node_modules/express/lib/router/layer.js:172:12) Mar 14 14:21:01 volumio volumio[838]: at Layer.match (/volumio/node_modules/express/lib/router/layer.js:148:15) Mar 14 14:21:01 volumio volumio[838]: at matchLayer (/volumio/node_modules/express/lib/router/index.js:574:18) Mar 14 14:21:01 volumio volumio[838]: at next (/volumio/node_modules/express/lib/router/index.js:220:15) Mar 14 14:21:01 volumio volumio[838]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:91:12) Mar 14 14:21:01 volumio volumio[838]: at trim_prefix (/volumio/node_modules/express/lib/router/index.js:317:13) Mar 14 14:21:01 volumio volumio[838]: at /volumio/node_modules/express/lib/router/index.js:284:7 Mar 14 14:21:01 volumio volumio[838]: at Function.process_params (/volumio/node_modules/express/lib/router/index.js:335:12) Mar 14 14:21:01 volumio volumio[838]: at next (/volumio/node_modules/express/lib/router/index.js:275:10) Mar 14 14:21:01 volumio go-librespot[2923]: time="2025-03-14T14:21:01+01:00" level=debug msg="completed challenge" Mar 14 14:21:01 volumio go-librespot[2923]: time="2025-03-14T14:21:01+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 14 14:21:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 14 14:21:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 14 14:21:02 volumio volumio[838]: URIError: Failed to decode param '%80../%80../%80../%80../%80../%80../windows/win.ini' Mar 14 14:21:02 volumio volumio[838]: at decodeURIComponent () Mar 14 14:21:02 volumio volumio[838]: at decode_param (/volumio/node_modules/express/lib/router/layer.js:172:12) Mar 14 14:21:02 volumio volumio[838]: at Layer.match (/volumio/node_modules/express/lib/router/layer.js:148:15) Mar 14 14:21:02 volumio volumio[838]: at matchLayer (/volumio/node_modules/express/lib/router/index.js:574:18) Mar 14 14:21:02 volumio volumio[838]: at next (/volumio/node_modules/express/lib/router/index.js:220:15) Mar 14 14:21:02 volumio volumio[838]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:91:12) Mar 14 14:21:02 volumio volumio[838]: at trim_prefix (/volumio/node_modules/express/lib/router/index.js:317:13) Mar 14 14:21:02 volumio volumio[838]: at /volumio/node_modules/express/lib/router/index.js:284:7 Mar 14 14:21:02 volumio volumio[838]: at Function.process_params (/volumio/node_modules/express/lib/router/index.js:335:12) Mar 14 14:21:02 volumio volumio[838]: at next (/volumio/node_modules/express/lib/router/index.js:275:10) Mar 14 14:21:02 volumio volumio[838]: URIError: Failed to decode param '%80../%80../%80../%80../%80../%80../winnt/win.ini' Mar 14 14:21:02 volumio volumio[838]: at decodeURIComponent () Mar 14 14:21:02 volumio volumio[838]: at decode_param (/volumio/node_modules/express/lib/router/layer.js:172:12) Mar 14 14:21:02 volumio volumio[838]: at Layer.match (/volumio/node_modules/express/lib/router/layer.js:148:15) Mar 14 14:21:02 volumio volumio[838]: at matchLayer (/volumio/node_modules/express/lib/router/index.js:574:18) Mar 14 14:21:02 volumio volumio[838]: at next (/volumio/node_modules/express/lib/router/index.js:220:15) Mar 14 14:21:02 volumio volumio[838]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:91:12) Mar 14 14:21:02 volumio volumio[838]: at trim_prefix (/volumio/node_modules/express/lib/router/index.js:317:13) Mar 14 14:21:02 volumio volumio[838]: at /volumio/node_modules/express/lib/router/index.js:284:7 Mar 14 14:21:02 volumio volumio[838]: at Function.process_params (/volumio/node_modules/express/lib/router/index.js:335:12) Mar 14 14:21:02 volumio volumio[838]: at next (/volumio/node_modules/express/lib/router/index.js:275:10) Mar 14 14:21:02 volumio volumio[838]: URIError: Failed to decode param '%c0.%c0./%c0.%c0./%c0.%c0./%c0.%c0./%c0.%c0./windows/win.ini' Mar 14 14:21:02 volumio volumio[838]: at decodeURIComponent () Mar 14 14:21:02 volumio volumio[838]: at decode_param (/volumio/node_modules/express/lib/router/layer.js:172:12) Mar 14 14:21:02 volumio volumio[838]: at Layer.match (/volumio/node_modules/express/lib/router/layer.js:148:15) Mar 14 14:21:02 volumio volumio[838]: at matchLayer (/volumio/node_modules/express/lib/router/index.js:574:18) Mar 14 14:21:02 volumio volumio[838]: at next (/volumio/node_modules/express/lib/router/index.js:220:15) Mar 14 14:21:02 volumio volumio[838]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:91:12) Mar 14 14:21:02 volumio volumio[838]: at trim_prefix (/volumio/node_modules/express/lib/router/index.js:317:13) Mar 14 14:21:02 volumio volumio[838]: at /volumio/node_modules/express/lib/router/index.js:284:7 Mar 14 14:21:02 volumio volumio[838]: at Function.process_params (/volumio/node_modules/express/lib/router/index.js:335:12) Mar 14 14:21:02 volumio volumio[838]: at next (/volumio/node_modules/express/lib/router/index.js:275:10) Mar 14 14:21:02 volumio volumio[838]: URIError: Failed to decode param '%c0.%c0./%c0.%c0./%c0.%c0./%c0.%c0./%c0.%c0./winnt/win.ini' Mar 14 14:21:02 volumio volumio[838]: at decodeURIComponent () Mar 14 14:21:02 volumio volumio[838]: at decode_param (/volumio/node_modules/express/lib/router/layer.js:172:12) Mar 14 14:21:02 volumio volumio[838]: at Layer.match (/volumio/node_modules/express/lib/router/layer.js:148:15) Mar 14 14:21:02 volumio volumio[838]: at matchLayer (/volumio/node_modules/express/lib/router/index.js:574:18) Mar 14 14:21:02 volumio volumio[838]: at next (/volumio/node_modules/express/lib/router/index.js:220:15) Mar 14 14:21:02 volumio volumio[838]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:91:12) Mar 14 14:21:02 volumio volumio[838]: at trim_prefix (/volumio/node_modules/express/lib/router/index.js:317:13) Mar 14 14:21:02 volumio volumio[838]: at /volumio/node_modules/express/lib/router/index.js:284:7 Mar 14 14:21:02 volumio volumio[838]: at Function.process_params (/volumio/node_modules/express/lib/router/index.js:335:12) Mar 14 14:21:02 volumio volumio[838]: at next (/volumio/node_modules/express/lib/router/index.js:275:10) Mar 14 14:21:02 volumio volumio[838]: URIError: Failed to decode param '%c0%2e%c0%2e/%c0%2e%c0%2e/%c0%2e%c0%2e/%c0%2e%c0%2e/windows/win.ini' Mar 14 14:21:02 volumio volumio[838]: at decodeURIComponent () Mar 14 14:21:02 volumio volumio[838]: at decode_param (/volumio/node_modules/express/lib/router/layer.js:172:12) Mar 14 14:21:02 volumio volumio[838]: at Layer.match (/volumio/node_modules/express/lib/router/layer.js:148:15) Mar 14 14:21:02 volumio volumio[838]: at matchLayer (/volumio/node_modules/express/lib/router/index.js:574:18) Mar 14 14:21:02 volumio volumio[838]: at next (/volumio/node_modules/express/lib/router/index.js:220:15) Mar 14 14:21:02 volumio volumio[838]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:91:12) Mar 14 14:21:02 volumio volumio[838]: at trim_prefix (/volumio/node_modules/express/lib/router/index.js:317:13) Mar 14 14:21:02 volumio volumio[838]: at /volumio/node_modules/express/lib/router/index.js:284:7 Mar 14 14:21:02 volumio volumio[838]: at Function.process_params (/volumio/node_modules/express/lib/router/index.js:335:12) Mar 14 14:21:02 volumio volumio[838]: at next (/volumio/node_modules/express/lib/router/index.js:275:10) Mar 14 14:21:02 volumio volumio[838]: URIError: Failed to decode param '%c0%2e%c0%2e/%c0%2e%c0%2e/%c0%2e%c0%2e/%c0%2e%c0%2e/winnt/win.ini' Mar 14 14:21:02 volumio volumio[838]: at decodeURIComponent () Mar 14 14:21:02 volumio volumio[838]: at decode_param (/volumio/node_modules/express/lib/router/layer.js:172:12) Mar 14 14:21:02 volumio volumio[838]: at Layer.match (/volumio/node_modules/express/lib/router/layer.js:148:15) Mar 14 14:21:02 volumio volumio[838]: at matchLayer (/volumio/node_modules/express/lib/router/index.js:574:18) Mar 14 14:21:02 volumio volumio[838]: at next (/volumio/node_modules/express/lib/router/index.js:220:15) Mar 14 14:21:02 volumio volumio[838]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:91:12) Mar 14 14:21:02 volumio volumio[838]: at trim_prefix (/volumio/node_modules/express/lib/router/index.js:317:13) Mar 14 14:21:02 volumio volumio[838]: at /volumio/node_modules/express/lib/router/index.js:284:7 Mar 14 14:21:02 volumio volumio[838]: at Function.process_params (/volumio/node_modules/express/lib/router/index.js:335:12) Mar 14 14:21:02 volumio volumio[838]: at next (/volumio/node_modules/express/lib/router/index.js:275:10) Mar 14 14:21:02 volumio volumio[838]: URIError: Failed to decode param '%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/windows/win.ini' Mar 14 14:21:02 volumio volumio[838]: at decodeURIComponent () Mar 14 14:21:02 volumio volumio[838]: at decode_param (/volumio/node_modules/express/lib/router/layer.js:172:12) Mar 14 14:21:02 volumio volumio[838]: at Layer.match (/volumio/node_modules/express/lib/router/layer.js:148:15) Mar 14 14:21:02 volumio volumio[838]: at matchLayer (/volumio/node_modules/express/lib/router/index.js:574:18) Mar 14 14:21:02 volumio volumio[838]: at next (/volumio/node_modules/express/lib/router/index.js:220:15) Mar 14 14:21:02 volumio volumio[838]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:91:12) Mar 14 14:21:02 volumio volumio[838]: at trim_prefix (/volumio/node_modules/express/lib/router/index.js:317:13) Mar 14 14:21:02 volumio volumio[838]: at /volumio/node_modules/express/lib/router/index.js:284:7 Mar 14 14:21:02 volumio volumio[838]: at Function.process_params (/volumio/node_modules/express/lib/router/index.js:335:12) Mar 14 14:21:02 volumio volumio[838]: at next (/volumio/node_modules/express/lib/router/index.js:275:10) Mar 14 14:21:02 volumio volumio[838]: URIError: Failed to decode param '%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/winnt/win.ini' Mar 14 14:21:02 volumio volumio[838]: at decodeURIComponent () Mar 14 14:21:02 volumio volumio[838]: at decode_param (/volumio/node_modules/express/lib/router/layer.js:172:12) Mar 14 14:21:02 volumio volumio[838]: at Layer.match (/volumio/node_modules/express/lib/router/layer.js:148:15) Mar 14 14:21:02 volumio volumio[838]: at matchLayer (/volumio/node_modules/express/lib/router/index.js:574:18) Mar 14 14:21:02 volumio volumio[838]: at next (/volumio/node_modules/express/lib/router/index.js:220:15) Mar 14 14:21:02 volumio volumio[838]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:91:12) Mar 14 14:21:02 volumio volumio[838]: at trim_prefix (/volumio/node_modules/express/lib/router/index.js:317:13) Mar 14 14:21:02 volumio volumio[838]: at /volumio/node_modules/express/lib/router/index.js:284:7 Mar 14 14:21:02 volumio volumio[838]: at Function.process_params (/volumio/node_modules/express/lib/router/index.js:335:12) Mar 14 14:21:02 volumio volumio[838]: at next (/volumio/node_modules/express/lib/router/index.js:275:10) Mar 14 14:21:02 volumio volumio[838]: URIError: Failed to decode param '%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/%uff0e%uff0e/etc/passwd' Mar 14 14:21:02 volumio volumio[838]: at decodeURIComponent () Mar 14 14:21:02 volumio volumio[838]: at decode_param (/volumio/node_modules/express/lib/router/layer.js:172:12) Mar 14 14:21:02 volumio volumio[838]: at Layer.match (/volumio/node_modules/express/lib/router/layer.js:148:15) Mar 14 14:21:02 volumio volumio[838]: at matchLayer (/volumio/node_modules/express/lib/router/index.js:574:18) Mar 14 14:21:02 volumio volumio[838]: at next (/volumio/node_modules/express/lib/router/index.js:220:15) Mar 14 14:21:02 volumio volumio[838]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:91:12) Mar 14 14:21:02 volumio volumio[838]: at trim_prefix (/volumio/node_modules/express/lib/router/index.js:317:13) Mar 14 14:21:02 volumio volumio[838]: at /volumio/node_modules/express/lib/router/index.js:284:7 Mar 14 14:21:02 volumio volumio[838]: at Function.process_params (/volumio/node_modules/express/lib/router/index.js:335:12) Mar 14 14:21:02 volumio volumio[838]: at next (/volumio/node_modules/express/lib/router/index.js:275:10) Mar 14 14:21:02 volumio volumio[838]: info: Initializing connection to go-librespot Websocket Mar 14 14:21:02 volumio volumio[838]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 14 14:21:02 volumio wpa_supplicant[754]: wlan0: Failed to initiate sched scan Mar 14 14:21:03 volumio volumio[838]: STREAMING PROXY: Handling url / Mar 14 14:21:03 volumio volumio[838]: info: No valid Plugin REST Endpoint Mar 14 14:21:03 volumio volumio[838]: STREAMING PROXY: Error: Failed to retrieve proper real streamUrl Mar 14 14:21:04 volumio volumio[838]: STREAMING PROXY: Handling url / Mar 14 14:21:04 volumio volumio[838]: info: No valid Plugin REST Endpoint Mar 14 14:21:04 volumio volumio[838]: STREAMING PROXY: Error: Failed to retrieve proper real streamUrl Mar 14 14:21:05 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 14 14:21:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31567. Mar 14 14:21:05 volumio systemd[1]: Stopped go-librespot Daemon. Mar 14 14:21:05 volumio systemd[1]: Started go-librespot Daemon. Mar 14 14:21:05 volumio go-librespot[2931]: Librespot-go daemon starting... Mar 14 14:21:05 volumio go-librespot[2931]: time="2025-03-14T14:21:05+01:00" level=info msg="generated new device id: 66773d617af21af4d41fcdcd68418e78b92742a1" Mar 14 14:21:05 volumio go-librespot[2931]: time="2025-03-14T14:21:05+01:00" level=debug msg="stored credentials found for fone129" Mar 14 14:21:05 volumio go-librespot[2931]: time="2025-03-14T14:21:05+01:00" level=debug msg="obtained new client token: AADHYFsWQa0YDrjFcUQonmDTyqmEmse/fCW/MlnFz1YT9GIKXuG/+h+MR4EO3V7UP1WUku/d7fURGnvwWReQJv/tv3JsuVe3NxVp9QXSFMbCYbiZeRGPbHiNtJYzTHFhjSHvhjJCWobVpypUbTBHyitjxyJpRBVsCOqyvsL1xBMnEGKyRglX773/NOWF6sJlgP+vFS4BGbukUa5lxObSJF7neipoBisWUQbyobkNjX8wXP5R5hgQ6nk1PzM=" Mar 14 14:21:05 volumio go-librespot[2931]: time="2025-03-14T14:21:05+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 14 14:21:05 volumio go-librespot[2931]: time="2025-03-14T14:21:05+01:00" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed dialing accesspoint: dial tcp 34.158.1.133:4070: connect: connection refused" Mar 14 14:21:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 14 14:21:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 14 14:21:05 volumio volumio[838]: info: Initializing connection to go-librespot Websocket Mar 14 14:21:05 volumio volumio[838]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 14 14:21:08 volumio rpcbind[2939]: connect from 192.168.40.53 to set(nfs): indirect call not allowed Mar 14 14:21:08 volumio wpa_supplicant[754]: wlan0: Failed to initiate sched scan Mar 14 14:21:08 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 14 14:21:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31568. Mar 14 14:21:08 volumio systemd[1]: Stopped go-librespot Daemon. Mar 14 14:21:08 volumio systemd[1]: Started go-librespot Daemon. Mar 14 14:21:08 volumio go-librespot[2940]: Librespot-go daemon starting... Mar 14 14:21:08 volumio volumio[838]: info: Initializing connection to go-librespot Websocket Mar 14 14:21:08 volumio volumio[838]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 14 14:21:08 volumio go-librespot[2940]: time="2025-03-14T14:21:08+01:00" level=info msg="generated new device id: 75d1428a77f09b49386c12adff9c3475f5348852" Mar 14 14:21:08 volumio go-librespot[2940]: time="2025-03-14T14:21:08+01:00" level=debug msg="stored credentials found for fone129" Mar 14 14:21:09 volumio go-librespot[2940]: time="2025-03-14T14:21:09+01:00" level=debug msg="obtained new client token: AADOtcl6lor8G3npjo9ednz8XkXTQVC9ucSL2fxkIJVeM5fXlB8WEo8VXQ/BlzmumpcGpqBGMNGX8e5T5iLrJYqf3zfrISBIMnfXyHxsaGH4TiBpHChaMaZsamUOlz3H6QfrHB926sG3z00IXknJkfvcRTq7fedSOxbJstCpmHcj4Jd+OFLg2iICWkYVyc9XKXOVI8qX6BGOz/55soXsruBm+X/GkCMAEHXC664+bg4yxjw/ZPSrzBQo" Mar 14 14:21:09 volumio go-librespot[2940]: time="2025-03-14T14:21:09+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 14 14:21:09 volumio go-librespot[2940]: time="2025-03-14T14:21:09+01:00" level=debug msg="completed keyexchange" Mar 14 14:21:10 volumio go-librespot[2940]: time="2025-03-14T14:21:10+01:00" level=debug msg="completed challenge" Mar 14 14:21:10 volumio go-librespot[2940]: time="2025-03-14T14:21:10+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 14 14:21:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 14 14:21:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 14 14:21:11 volumio volumio[838]: info: Initializing connection to go-librespot Websocket Mar 14 14:21:11 volumio volumio[838]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 14 14:21:13 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 14 14:21:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31569. Mar 14 14:21:13 volumio systemd[1]: Stopped go-librespot Daemon. Mar 14 14:21:13 volumio systemd[1]: Started go-librespot Daemon. Mar 14 14:21:13 volumio go-librespot[2948]: Librespot-go daemon starting... Mar 14 14:21:13 volumio go-librespot[2948]: time="2025-03-14T14:21:13+01:00" level=info msg="generated new device id: 2dda03022144f018990be96d28f8c1ad7dfb98ea" Mar 14 14:21:13 volumio go-librespot[2948]: time="2025-03-14T14:21:13+01:00" level=debug msg="stored credentials found for fone129" Mar 14 14:21:13 volumio go-librespot[2948]: time="2025-03-14T14:21:13+01:00" level=debug msg="obtained new client token: AADsnKtgKxifsKRaGayDIOAfMo/N9+YvFD6kvX4nRNyGrmwVGAzmNjYGtqG5aWHNjwjRITcto0k4wHOULkIsSvhSFtoK8pAUg739HsF1I/NYP6hRzmb1DFV8918b1HxNWRlNGvltKEqQfxuHaeznOMhcJne/vJZzMNt5YaIasULIWUMndXYY5jd6/PGhyjvrHVMPUUaHq657PHBJaggXDoF8vBi9GyZ9HY+mmP1lzvUglQJB8rdVQ7BaE7Q=" Mar 14 14:21:14 volumio wpa_supplicant[754]: wlan0: Failed to initiate sched scan Mar 14 14:21:14 volumio go-librespot[2948]: time="2025-03-14T14:21:14+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 14 14:21:14 volumio go-librespot[2948]: time="2025-03-14T14:21:14+01:00" level=debug msg="completed keyexchange" Mar 14 14:21:14 volumio go-librespot[2948]: time="2025-03-14T14:21:14+01:00" level=debug msg="completed challenge" Mar 14 14:21:14 volumio volumio[838]: info: Initializing connection to go-librespot Websocket Mar 14 14:21:14 volumio go-librespot[2948]: time="2025-03-14T14:21:14+01:00" level=debug msg="new websocket client" Mar 14 14:21:14 volumio volumio[838]: info: Connection to go-librespot Websocket established Mar 14 14:21:14 volumio go-librespot[2948]: time="2025-03-14T14:21:14+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 14 14:21:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 14 14:21:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 14 14:21:14 volumio volumio[838]: info: Connection to go-librespot Websocket closed Mar 14 14:21:15 volumio volumio[838]: STREAMING PROXY: Handling url /home.asp Mar 14 14:21:15 volumio volumio[838]: info: No valid Plugin REST Endpoint Mar 14 14:21:15 volumio volumio[838]: STREAMING PROXY: Error: Failed to retrieve proper real streamUrl Mar 14 14:21:17 volumio volumio[838]: info: Getting Spotify volume Mar 14 14:21:17 volumio volumio[838]: (node:838) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 14 14:21:17 volumio volumio[838]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 14 14:21:17 volumio volumio[838]: (node:838) 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: 6245) Mar 14 14:21:17 volumio volumio[838]: info: Initializing connection to go-librespot Websocket Mar 14 14:21:17 volumio volumio[838]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 Mar 14 14:21:17 volumio volumio[838]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 14 14:21:18 volumio volumio[838]: info: CoreCommandRouter::volumioGetState Mar 14 14:21:18 volumio volumio[838]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Mar 14 14:21:18 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 14 14:21:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31570. Mar 14 14:21:18 volumio systemd[1]: Stopped go-librespot Daemon. Mar 14 14:21:18 volumio systemd[1]: Started go-librespot Daemon. Mar 14 14:21:18 volumio go-librespot[2956]: Librespot-go daemon starting... Mar 14 14:21:18 volumio go-librespot[2956]: time="2025-03-14T14:21:18+01:00" level=info msg="generated new device id: 60ee96f32cb0ed4cc2c88944d1ec507ec651c5a1" Mar 14 14:21:18 volumio go-librespot[2956]: time="2025-03-14T14:21:18+01:00" level=debug msg="stored credentials found for fone129" Mar 14 14:21:18 volumio go-librespot[2956]: time="2025-03-14T14:21:18+01:00" level=debug msg="obtained new client token: AABGRtGJY13G9Bp1jTs2IVZcF4CGMjSLvs/lXZCi2fdmGACbEFY+gln5eOqLaqG73Lv5mQb2AmhYi91zVmtKjhnhgtI0v8WWHOaD+ByafFdfcA0V0JSHtoWeTjOzRF8PmKtL29+SahoudHDVmpONdWBpz3njyHBad0DZcMSisuaeom7Mteke8V2eDeVrrkR2ATuil/HxXNjxXbPhuOIuSWma5hkQiSke7WfX1Tya3He1US+GWg0+sdec8eE=" Mar 14 14:21:18 volumio go-librespot[2956]: time="2025-03-14T14:21:18+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 14 14:21:18 volumio go-librespot[2956]: time="2025-03-14T14:21:18+01:00" level=debug msg="completed keyexchange" Mar 14 14:21:19 volumio go-librespot[2956]: time="2025-03-14T14:21:19+01:00" level=debug msg="completed challenge" Mar 14 14:21:19 volumio wpa_supplicant[754]: wlan0: Failed to initiate sched scan Mar 14 14:21:19 volumio go-librespot[2956]: time="2025-03-14T14:21:19+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 14 14:21:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 14 14:21:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 14 14:21:20 volumio volumio[838]: info: Initializing connection to go-librespot Websocket Mar 14 14:21:20 volumio volumio[838]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 14 14:21:22 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 14 14:21:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31571. Mar 14 14:21:22 volumio systemd[1]: Stopped go-librespot Daemon. Mar 14 14:21:22 volumio systemd[1]: Started go-librespot Daemon. Mar 14 14:21:22 volumio go-librespot[2964]: Librespot-go daemon starting... Mar 14 14:21:22 volumio go-librespot[2964]: time="2025-03-14T14:21:22+01:00" level=info msg="generated new device id: d961e212cf66e53556fe7ec8f92b778fa7f64aa7" Mar 14 14:21:22 volumio go-librespot[2964]: time="2025-03-14T14:21:22+01:00" level=debug msg="stored credentials found for fone129" Mar 14 14:21:23 volumio volumio[838]: STREAMING PROXY: Handling url / Mar 14 14:21:23 volumio volumio[838]: info: No valid Plugin REST Endpoint Mar 14 14:21:23 volumio volumio[838]: STREAMING PROXY: Error: Failed to retrieve proper real streamUrl Mar 14 14:21:23 volumio volumio[838]: STREAMING PROXY: Handling url / Mar 14 14:21:23 volumio volumio[838]: info: No valid Plugin REST Endpoint Mar 14 14:21:23 volumio volumio[838]: STREAMING PROXY: Error: Failed to retrieve proper real streamUrl Mar 14 14:21:23 volumio go-librespot[2964]: time="2025-03-14T14:21:23+01:00" level=debug msg="obtained new client token: AABFrfooqVoKcN+2JjgA5HR0G+oVX4TBFuY/B+lm8BkoxvRtD0FzPHwvKQBNrzTgibdr+mXbFf9gNj87RKZ471nr7a/iq4N6jInMxfNE42Uw2TXeGovVJsIvGrq54QA/RFwz9pJfMP5vMp7Dd7ZBSrbw+DOBGpzBKAYEVk0Jh9m33QeZnp/A8OGNKtqZ3l/WuNk1Mv143BoRGw4NJWFb6HvLFiII/cc3q3o5GNWHPSyDiAIsKAhTsedW9fQ=" Mar 14 14:21:23 volumio volumio[838]: info: Initializing connection to go-librespot Websocket Mar 14 14:21:24 volumio go-librespot[2964]: time="2025-03-14T14:21:23+01:00" level=debug msg="new websocket client" Mar 14 14:21:24 volumio volumio[838]: info: Connection to go-librespot Websocket established Mar 14 14:21:24 volumio go-librespot[2964]: time="2025-03-14T14:21:24+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 14 14:21:25 volumio wpa_supplicant[754]: wlan0: Failed to initiate sched scan Mar 14 14:21:25 volumio go-librespot[2964]: time="2025-03-14T14:21:25+01:00" level=debug msg="completed keyexchange" Mar 14 14:21:25 volumio go-librespot[2964]: time="2025-03-14T14:21:25+01:00" level=debug msg="completed challenge" Mar 14 14:21:25 volumio go-librespot[2964]: time="2025-03-14T14:21:25+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 14 14:21:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 14 14:21:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 14 14:21:25 volumio volumio[838]: info: Connection to go-librespot Websocket closed Mar 14 14:21:26 volumio volumio[838]: STREAMING PROXY: Handling url / Mar 14 14:21:26 volumio volumio[838]: info: No valid Plugin REST Endpoint Mar 14 14:21:26 volumio volumio[838]: STREAMING PROXY: Error: Failed to retrieve proper real streamUrl Mar 14 14:21:27 volumio volumio[838]: info: Getting Spotify volume Mar 14 14:21:27 volumio volumio[838]: (node:838) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 14 14:21:27 volumio volumio[838]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 14 14:21:27 volumio volumio[838]: (node:838) 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: 6246) Mar 14 14:21:27 volumio volumio[838]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 Mar 14 14:21:27 volumio volumio[838]: info: CoreCommandRouter::volumioGetState Mar 14 14:21:27 volumio volumio[838]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Mar 14 14:21:28 volumio volumio[838]: STREAMING PROXY: Handling url / Mar 14 14:21:28 volumio volumio[838]: info: No valid Plugin REST Endpoint Mar 14 14:21:28 volumio volumio[838]: STREAMING PROXY: Error: Failed to retrieve proper real streamUrl Mar 14 14:21:28 volumio volumio[838]: info: Initializing connection to go-librespot Websocket Mar 14 14:21:28 volumio volumio[838]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 14 14:21:28 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 14 14:21:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31572. Mar 14 14:21:28 volumio systemd[1]: Stopped go-librespot Daemon. Mar 14 14:21:28 volumio systemd[1]: Started go-librespot Daemon. Mar 14 14:21:28 volumio go-librespot[2972]: Librespot-go daemon starting... Mar 14 14:21:28 volumio go-librespot[2972]: time="2025-03-14T14:21:28+01:00" level=info msg="generated new device id: 654b00b574c9012edb91151413d7e8fba15ee1f5" Mar 14 14:21:28 volumio go-librespot[2972]: time="2025-03-14T14:21:28+01:00" level=debug msg="stored credentials found for fone129" Mar 14 14:21:29 volumio go-librespot[2972]: time="2025-03-14T14:21:29+01:00" level=debug msg="obtained new client token: AAB9GKwJLFiwI7Hly8rG6SjEkjoC4dfZB8DcUtB95jN/GxKY/A1TEsUvOOo9gSQ4DJKW2Nwl9/pScJJTwMR4SVBX8G95UHUAKMh+laJyeJl+xSqSRppxDjSVs+FfapUkFNH6mGh4hZnQqLOK337fT8RCBOUMKQnVAvKv0ig7fI7VmgcSKN9HEnwWChkpoS0oGVuk/46H9nsSD0yNl7oKR4lEkUOLXQ7yzXaQJTImJV4ZmoKgSyZygb5x28M=" Mar 14 14:21:29 volumio go-librespot[2972]: time="2025-03-14T14:21:29+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 14 14:21:29 volumio go-librespot[2972]: time="2025-03-14T14:21:29+01:00" level=debug msg="completed keyexchange" Mar 14 14:21:30 volumio go-librespot[2972]: time="2025-03-14T14:21:30+01:00" level=debug msg="completed challenge" Mar 14 14:21:30 volumio go-librespot[2972]: time="2025-03-14T14:21:30+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 14 14:21:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 14 14:21:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 14 14:21:30 volumio wpa_supplicant[754]: wlan0: Failed to initiate sched scan Mar 14 14:21:31 volumio volumio[838]: info: Initializing connection to go-librespot Websocket Mar 14 14:21:31 volumio volumio[838]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 14 14:21:33 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 14 14:21:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31573. Mar 14 14:21:33 volumio systemd[1]: Stopped go-librespot Daemon. Mar 14 14:21:33 volumio systemd[1]: Started go-librespot Daemon. Mar 14 14:21:33 volumio go-librespot[2980]: Librespot-go daemon starting... Mar 14 14:21:33 volumio go-librespot[2980]: time="2025-03-14T14:21:33+01:00" level=info msg="generated new device id: 359812d4c31ef83b36aaf71512cab0a624b83614" Mar 14 14:21:33 volumio go-librespot[2980]: time="2025-03-14T14:21:33+01:00" level=debug msg="stored credentials found for fone129" Mar 14 14:21:34 volumio go-librespot[2980]: time="2025-03-14T14:21:34+01:00" level=debug msg="obtained new client token: AAAxrA68+B8qW3JL4csURGGZS05gtntOBm6vOP/y68uFiHXhHduwELRVw0AakCukfg/4cm8PmPcMgj4nWmGvf1/vtaJHhXpI1Y9ukRym2sHQzYrQpBHXIbFHQs0FelZ/xjMH4ND8DmqYZz3GWmwDM4HPzJJ29Bk08e5PyVH1VdI8JYGlNDMi+QuzD2Qga+8v9I94fl9vNJ1PMQ8lCm9U/Dwng3FHNk0FfDx7rxEJupb+IPNIV1gPbd8a" Mar 14 14:21:34 volumio go-librespot[2980]: time="2025-03-14T14:21:34+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 14 14:21:34 volumio go-librespot[2980]: time="2025-03-14T14:21:34+01:00" level=debug msg="completed keyexchange" Mar 14 14:21:34 volumio volumio[838]: info: Initializing connection to go-librespot Websocket Mar 14 14:21:34 volumio go-librespot[2980]: time="2025-03-14T14:21:34+01:00" level=debug msg="new websocket client" Mar 14 14:21:34 volumio volumio[838]: info: Connection to go-librespot Websocket established Mar 14 14:21:34 volumio go-librespot[2980]: time="2025-03-14T14:21:34+01:00" level=debug msg="completed challenge" Mar 14 14:21:34 volumio go-librespot[2980]: time="2025-03-14T14:21:34+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 14 14:21:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 14 14:21:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 14 14:21:34 volumio volumio[838]: info: Connection to go-librespot Websocket closed Mar 14 14:21:35 volumio volumio[838]: STREAMING PROXY: Handling url / Mar 14 14:21:35 volumio volumio[838]: info: No valid Plugin REST Endpoint Mar 14 14:21:35 volumio volumio[838]: STREAMING PROXY: Error: Failed to retrieve proper real streamUrl Mar 14 14:21:36 volumio wpa_supplicant[754]: wlan0: Failed to initiate sched scan Mar 14 14:21:37 volumio volumio[838]: info: Getting Spotify volume Mar 14 14:21:37 volumio volumio[838]: (node:838) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 14 14:21:37 volumio volumio[838]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 14 14:21:37 volumio volumio[838]: (node:838) 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: 6247) Mar 14 14:21:37 volumio volumio[838]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 Mar 14 14:21:37 volumio volumio[838]: info: CoreCommandRouter::volumioGetState Mar 14 14:21:37 volumio volumio[838]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 Mar 14 14:21:37 volumio volumio[838]: info: Initializing connection to go-librespot Websocket Mar 14 14:21:38 volumio volumio[838]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 14 14:21:38 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 14 14:21:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31574. Mar 14 14:21:38 volumio systemd[1]: Stopped go-librespot Daemon. Mar 14 14:21:38 volumio systemd[1]: Started go-librespot Daemon. Mar 14 14:21:38 volumio go-librespot[2988]: Librespot-go daemon starting... Mar 14 14:21:38 volumio go-librespot[2988]: time="2025-03-14T14:21:38+01:00" level=info msg="generated new device id: dcb1a308ba4b165d153745f79407fe40c9537215" Mar 14 14:21:38 volumio go-librespot[2988]: time="2025-03-14T14:21:38+01:00" level=debug msg="stored credentials found for fone129" Mar 14 14:21:38 volumio shairport-sync[1014]: no RTSP header received Mar 14 14:21:38 volumio go-librespot[2988]: time="2025-03-14T14:21:38+01:00" level=debug msg="obtained new client token: AADy147mb4LZnsMKLDQu0EFyFJeAilmeeMGhEh2kFGEtLRlNxbOGLvjzsE2PQ1Rh+7Mv5uh8azE0OpBfoNP5tvJO2xzrhZ0mQITZ8/dErjNOxpDZqyPFJYECCgt2TRAVN4U3U1eNCSqBhg5SeMJTaeNnG0VPBLgykCWitVOtbTN+mwIErvfoPRLqsUgFVxWXT+vPmnLBJi0j/16AMIro57QY8C7SH8QNEO7+/ubEE30ZWZfpSWfe7QjYLZc=" Mar 14 14:21:38 volumio go-librespot[2988]: time="2025-03-14T14:21:38+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 14 14:21:38 volumio go-librespot[2988]: time="2025-03-14T14:21:38+01:00" level=debug msg="completed keyexchange" Mar 14 14:21:39 volumio go-librespot[2988]: time="2025-03-14T14:21:39+01:00" level=debug msg="completed challenge" Mar 14 14:21:39 volumio go-librespot[2988]: time="2025-03-14T14:21:39+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 14 14:21:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 14 14:21:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 14 14:21:41 volumio volumio[838]: info: Initializing connection to go-librespot Websocket Mar 14 14:21:41 volumio volumio[838]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 14 14:21:41 volumio wpa_supplicant[754]: wlan0: Failed to initiate sched scan Mar 14 14:21:42 volumio volumio[838]: STREAMING PROXY: Handling url / Mar 14 14:21:42 volumio volumio[838]: info: No valid Plugin REST Endpoint Mar 14 14:21:42 volumio volumio[838]: STREAMING PROXY: Error: Failed to retrieve proper real streamUrl Mar 14 14:21:42 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 14 14:21:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31575. Mar 14 14:21:42 volumio systemd[1]: Stopped go-librespot Daemon. Mar 14 14:21:42 volumio systemd[1]: Started go-librespot Daemon. Mar 14 14:21:42 volumio go-librespot[2997]: Librespot-go daemon starting... Mar 14 14:21:42 volumio go-librespot[2997]: time="2025-03-14T14:21:42+01:00" level=info msg="generated new device id: 2ea19273a46c3b6a3f64b89ef67e03551e1f6952" Mar 14 14:21:42 volumio go-librespot[2997]: time="2025-03-14T14:21:42+01:00" level=debug msg="stored credentials found for fone129" Mar 14 14:21:43 volumio go-librespot[2997]: time="2025-03-14T14:21:43+01:00" level=debug msg="obtained new client token: AADg30O4zc9Zoz/mi4s4DV/mamhCpZc8NZ3uhG5n84O6ewsoDWwwARFFzXpfNEe5vRKnkJFPAYez5LJo9QXIc/Kwg4O/tlST0oHmTrwX8r7TmbS8HKFBG6vCCqNarHK3BCBNZ9UP1/7JJhNu4aW+Bk75cCT4MC4hBUxELlFiXq99wF1xHRmfQp7zpgCa8j266Rsfm8hcrRTIFbfIslr/hl3BIxK7PLlBVnEk6wLI/zZ2rjdz46yvB0pL6Pw=" Mar 14 14:21:43 volumio go-librespot[2997]: time="2025-03-14T14:21:43+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 14 14:21:43 volumio go-librespot[2997]: time="2025-03-14T14:21:43+01:00" level=debug msg="completed keyexchange" Mar 14 14:21:43 volumio go-librespot[2997]: time="2025-03-14T14:21:43+01:00" level=debug msg="completed challenge" Mar 14 14:21:43 volumio go-librespot[2997]: time="2025-03-14T14:21:43+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 14 14:21:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 14 14:21:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 14 14:21:44 volumio volumio[838]: info: Initializing connection to go-librespot Websocket Mar 14 14:21:44 volumio volumio[838]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 14 14:21:46 volumio volumio[838]: STREAMING PROXY: Handling url / Mar 14 14:21:46 volumio volumio[838]: info: No valid Plugin REST Endpoint Mar 14 14:21:46 volumio volumio[838]: STREAMING PROXY: Error: Failed to retrieve proper real streamUrl Mar 14 14:21:46 volumio volumio[838]: STREAMING PROXY: Handling url / Mar 14 14:21:46 volumio volumio[838]: info: No valid Plugin REST Endpoint Mar 14 14:21:46 volumio volumio[838]: STREAMING PROXY: Error: Failed to retrieve proper real streamUrl Mar 14 14:21:47 volumio volumio[838]: info: Initializing connection to go-librespot Websocket Mar 14 14:21:47 volumio volumio[838]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 14 14:21:47 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 14 14:21:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31576. Mar 14 14:21:47 volumio systemd[1]: Stopped go-librespot Daemon. Mar 14 14:21:47 volumio systemd[1]: Started go-librespot Daemon. Mar 14 14:21:47 volumio go-librespot[3005]: Librespot-go daemon starting... Mar 14 14:21:47 volumio wpa_supplicant[754]: wlan0: Failed to initiate sched scan Mar 14 14:21:47 volumio go-librespot[3005]: time="2025-03-14T14:21:47+01:00" level=info msg="generated new device id: 43be1ff079929667531e9e728850f6bc589a9736" Mar 14 14:21:47 volumio go-librespot[3005]: time="2025-03-14T14:21:47+01:00" level=debug msg="stored credentials found for fone129" Mar 14 14:21:47 volumio volumio[838]: STREAMING PROXY: Handling url / Mar 14 14:21:47 volumio volumio[838]: info: No valid Plugin REST Endpoint Mar 14 14:21:47 volumio volumio[838]: STREAMING PROXY: Error: Failed to retrieve proper real streamUrl Mar 14 14:21:47 volumio go-librespot[3005]: time="2025-03-14T14:21:47+01:00" level=debug msg="obtained new client token: AABwrY8DjSflreGYtsaNuij4zsvHXZ2Mr1rmnieYF4hUTnDuq9WHV2OA2c4aJTx+55xk80lc7ZwEyNdDZrhA92bovjWdbEvm6Z4cbbLxoeWpUL0fhepw2olNgqhQKcaaThp2NmfAbGK9g7HMBVxQwINNtK5bMNxBpqDnMUDPTQ3Bk2jE3DACmxCHoLivajWYdgC651ruAjTczopgQFYBv7rNvZkY//xhqSpBYXjxUlR/SWu4Z3DU2sbnsMs=" Mar 14 14:21:47 volumio go-librespot[3005]: time="2025-03-14T14:21:47+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 14 14:21:47 volumio go-librespot[3005]: time="2025-03-14T14:21:47+01:00" level=debug msg="completed keyexchange" Mar 14 14:21:48 volumio go-librespot[3005]: time="2025-03-14T14:21:48+01:00" level=debug msg="completed challenge" Mar 14 14:21:48 volumio go-librespot[3005]: time="2025-03-14T14:21:48+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 14 14:21:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 14 14:21:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 14 14:21:50 volumio volumio[838]: info: Initializing connection to go-librespot Websocket Mar 14 14:21:50 volumio volumio[838]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 14 14:21:51 volumio volumio[838]: STREAMING PROXY: Handling url / Mar 14 14:21:51 volumio volumio[838]: info: No valid Plugin REST Endpoint Mar 14 14:21:51 volumio volumio[838]: STREAMING PROXY: Error: Failed to retrieve proper real streamUrl Mar 14 14:21:51 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 14 14:21:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31577. Mar 14 14:21:51 volumio systemd[1]: Stopped go-librespot Daemon. Mar 14 14:21:51 volumio systemd[1]: Started go-librespot Daemon. Mar 14 14:21:51 volumio go-librespot[3013]: Librespot-go daemon starting... Mar 14 14:21:51 volumio go-librespot[3013]: time="2025-03-14T14:21:51+01:00" level=info msg="generated new device id: b74722ed5cc6aea04ca2e15b66e7e29f1f580394" Mar 14 14:21:51 volumio go-librespot[3013]: time="2025-03-14T14:21:51+01:00" level=debug msg="stored credentials found for fone129" Mar 14 14:21:52 volumio go-librespot[3013]: time="2025-03-14T14:21:52+01:00" level=debug msg="obtained new client token: AACUqD5kvB3YClJeQDOImlsiPEoyDCVf5x9WDvUkU6PCtHuOH2UwY+9Zjwme1awhsB5V4tZqgTs8a22VQaJsYejQ5tOw+J/74OPIgXXKJFuzRJ8YsKlW5oTjXjDvF9Ue2x/ANQ9LCiKepr28aWoI8ixkLqXlAPseZ7/1Hvt5YVO/8FgtvRCdYcSl0nRTC106A689wHvzOZPowuuP9Z4b4ofZkXDP1Uo9XHJ1MIoZHR/y3i2Duj3P3rAD21g=" Mar 14 14:21:52 volumio go-librespot[3013]: time="2025-03-14T14:21:52+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 14 14:21:52 volumio go-librespot[3013]: time="2025-03-14T14:21:52+01:00" level=debug msg="completed keyexchange" Mar 14 14:21:52 volumio wpa_supplicant[754]: wlan0: Failed to initiate sched scan Mar 14 14:21:52 volumio go-librespot[3013]: time="2025-03-14T14:21:52+01:00" level=debug msg="completed challenge" Mar 14 14:21:52 volumio go-librespot[3013]: time="2025-03-14T14:21:52+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Mar 14 14:21:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 14 14:21:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 14 14:21:53 volumio volumio[838]: info: Initializing connection to go-librespot Websocket Mar 14 14:21:53 volumio volumio[838]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 14 14:21:56 volumio volumio[838]: info: Initializing connection to go-librespot Websocket Mar 14 14:21:56 volumio volumio[838]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 14 14:21:56 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 14 14:21:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31578. Mar 14 14:21:56 volumio systemd[1]: Stopped go-librespot Daemon. Mar 14 14:21:56 volumio systemd[1]: Started go-librespot Daemon. Mar 14 14:21:56 volumio go-librespot[3021]: Librespot-go daemon starting... Mar 14 14:21:56 volumio go-librespot[3021]: time="2025-03-14T14:21:56+01:00" level=info msg="generated new device id: bac5f61e73f17380fa01185a6060d48698219e04" Mar 14 14:21:56 volumio go-librespot[3021]: time="2025-03-14T14:21:56+01:00" level=debug msg="stored credentials found for fone129" Mar 14 14:21:56 volumio volumio[838]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 14 14:21:56 volumio volumio[838]: Error: read ECONNRESET Mar 14 14:21:56 volumio volumio[838]: at TCP.onStreamRead (internal/stream_base_commons.js:209:20) { Mar 14 14:21:56 volumio volumio[838]: errno: -104, Mar 14 14:21:56 volumio volumio[838]: code: 'ECONNRESET', Mar 14 14:21:56 volumio volumio[838]: syscall: 'read' Mar 14 14:21:56 volumio volumio[838]: } Mar 14 14:21:56 volumio volumio[838]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 14 14:21:56 volumio go-librespot[3021]: time="2025-03-14T14:21:56+01:00" level=debug msg="obtained new client token: AACjM6PIMp5fyNP4wIWun8zwq1AGNbpsiLnP3gVksnsRM31bLueCtFnrdzV84C+WnzIjTIbRMCcnJTOZwwmsc4fCYa8Ow3ShTqQ3IGzqhozu1n/GAWkl8PF+UEpxPv0X0jshNS9weKF2PzaD7SFmUxEBpi4MeMus/T/cPbTtrzkR2GSXBfnaG2mTmmAXPkl94c5hbc/ipF0DkAp3eUzYBIcWtTNIxahL/v7a1Un2p7/OfbSUPyUpQc+GeVY=" Mar 14 14:21:56 volumio go-librespot[3021]: time="2025-03-14T14:21:56+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 14 14:21:56 volumio go-librespot[3021]: time="2025-03-14T14:21:56+01:00" level=debug msg="completed keyexchange" Mar 14 14:21:56 volumio sudo[3038]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-03-14 14:20 Mar 14 14:21:56 volumio sudo[3038]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="cd8cf34b47ce852e70b71e6f7b6e0265f7fdb695" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="8f88153f9a18f312d56050e6613b45a852ac819a" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 27 Sep 2023 11:35:49 AM CEST" VOLUMIO_VERSION="3.546" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="6823c0d83061ff736b7e0dd4481bc496"