-- Logs begin at Sun 2025-02-16 17:32:37 CST, end at Sun 2025-02-16 20:16:29 CST. -- Feb 16 20:15:00 volumio volumio[984]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Feb 16 20:15:00 volumio volumio[984]: info: Preload queue cleared Feb 16 20:15:02 volumio volumio[984]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Feb 16 20:15:02 volumio volumio[984]: info: Preload queue cleared Feb 16 20:15:02 volumio volumio[984]: info: Initializing connection to go-librespot Websocket Feb 16 20:15:02 volumio volumio[984]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 16 20:15:02 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 16 20:15:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 580393. Feb 16 20:15:02 volumio systemd[1]: Stopped go-librespot Daemon. Feb 16 20:15:02 volumio systemd[1]: Started go-librespot Daemon. Feb 16 20:15:02 volumio go-librespot[2219]: Librespot-go daemon starting... Feb 16 20:15:02 volumio go-librespot[2219]: time="2025-02-16T20:15:02+08:00" level=info msg="generated new device id: c4ae0df91b1ffd76f84e5093a2cac6b5150ebb6f" Feb 16 20:15:02 volumio go-librespot[2219]: time="2025-02-16T20:15:02+08:00" level=debug msg="stored credentials found for elvisbar" Feb 16 20:15:02 volumio go-librespot[2219]: time="2025-02-16T20:15:02+08:00" level=debug msg="obtained new client token: AAA/79ZFITrZ64mAsFDdf+uMfk9qN3ZKDterBGJvTtSvj/FA0wS0Og8pm/hkHmh5K/QWQpNfqEXTbcq5iUlWX319D01dfy+qJQkl5km5ubbJvi4RymvM/d2skB7x9EUKBupnkJbirc3nQlfx+17hPzTMO5nBBgFvGWkYvORTQz7W49Bli0f2Yu/u8xS9719zmVhsvxFddqZiOBvZFdukHfX5atbNiIp4slCPfteoqCn+goyjGqa+26amO8xMCzs=" Feb 16 20:15:03 volumio go-librespot[2219]: time="2025-02-16T20:15:03+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 16 20:15:03 volumio go-librespot[2219]: time="2025-02-16T20:15:03+08:00" level=debug msg="completed keyexchange" Feb 16 20:15:03 volumio volumio[984]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 16 20:15:03 volumio volumio[984]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Feb 16 20:15:03 volumio volumio[984]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Feb 16 20:15:03 volumio volumio[984]: info: Received Get System Version Feb 16 20:15:03 volumio volumio[984]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 16 20:15:03 volumio volumio[984]: info: Received Get System Info Feb 16 20:15:03 volumio volumio[984]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 16 20:15:03 volumio volumio[984]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 16 20:15:03 volumio volumio[984]: info: Discovery: Getting this device information Feb 16 20:15:03 volumio volumio[984]: info: CoreCommandRouter::volumioGetState Feb 16 20:15:03 volumio volumio[984]: info: CorePlayQueue::getTrack 6 Feb 16 20:15:03 volumio volumio[984]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 16 20:15:03 volumio go-librespot[2219]: time="2025-02-16T20:15:03+08:00" level=debug msg="completed challenge" Feb 16 20:15:03 volumio go-librespot[2219]: time="2025-02-16T20:15:03+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 16 20:15:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 16 20:15:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 16 20:15:05 volumio volumio[984]: info: Initializing connection to go-librespot Websocket Feb 16 20:15:05 volumio volumio[984]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 16 20:15:06 volumio volumio[984]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Feb 16 20:15:06 volumio volumio[984]: info: Preload queue cleared Feb 16 20:15:06 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 16 20:15:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 580394. Feb 16 20:15:06 volumio systemd[1]: Stopped go-librespot Daemon. Feb 16 20:15:06 volumio systemd[1]: Started go-librespot Daemon. Feb 16 20:15:06 volumio go-librespot[2230]: Librespot-go daemon starting... Feb 16 20:15:06 volumio go-librespot[2230]: time="2025-02-16T20:15:06+08:00" level=info msg="generated new device id: d96b939b2dd694871d86fa25317006d3d0eb44af" Feb 16 20:15:06 volumio go-librespot[2230]: time="2025-02-16T20:15:06+08:00" level=debug msg="stored credentials found for elvisbar" Feb 16 20:15:07 volumio go-librespot[2230]: time="2025-02-16T20:15:07+08:00" level=debug msg="obtained new client token: AABu5ozh4Jl+PrVUMlP/NLAZ7hdkPEvYWPfWOheSvaTA5DK7/S0WOH7goeC2Cy9KWr52JXccWxGdhMElii9ILtgdzRplI+Yiji0/hQM7p5xmuQbfeMvIO/MZi9x/vFnSJ1uEZ5J4fwX5WqWkA9uibNPuTTEm9DDhmXV1QNO4efmLEih2kFn2raQhAmHjcckk8FefTW+qLDX1Ann503BBvxBfOgNiD3/zU/ityteCG473a3BQtvGfEbN0PKJi" Feb 16 20:15:07 volumio go-librespot[2230]: time="2025-02-16T20:15:07+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 16 20:15:07 volumio go-librespot[2230]: time="2025-02-16T20:15:07+08:00" level=debug msg="completed keyexchange" Feb 16 20:15:07 volumio go-librespot[2230]: time="2025-02-16T20:15:07+08:00" level=debug msg="completed challenge" Feb 16 20:15:07 volumio go-librespot[2230]: time="2025-02-16T20:15:07+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 16 20:15:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 16 20:15:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 16 20:15:07 volumio volumio[984]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Feb 16 20:15:09 volumio volumio[984]: info: Initializing connection to go-librespot Websocket Feb 16 20:15:09 volumio volumio[984]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 16 20:15:09 volumio volumio[984]: info: Preload queue cleared Feb 16 20:15:10 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 16 20:15:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 580395. Feb 16 20:15:10 volumio systemd[1]: Stopped go-librespot Daemon. Feb 16 20:15:10 volumio volumio[984]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 16 20:15:10 volumio volumio[984]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 16 20:15:10 volumio volumio[984]: info: Discovery: Getting this device information Feb 16 20:15:10 volumio volumio[984]: info: CoreCommandRouter::volumioGetState Feb 16 20:15:10 volumio volumio[984]: info: CorePlayQueue::getTrack 6 Feb 16 20:15:10 volumio volumio[984]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 16 20:15:10 volumio systemd[1]: Started go-librespot Daemon. Feb 16 20:15:10 volumio go-librespot[2239]: Librespot-go daemon starting... Feb 16 20:15:10 volumio go-librespot[2239]: time="2025-02-16T20:15:10+08:00" level=info msg="generated new device id: 2370cc88ca8722a9083d400973a3851e405bc67c" Feb 16 20:15:10 volumio go-librespot[2239]: time="2025-02-16T20:15:10+08:00" level=debug msg="stored credentials found for elvisbar" Feb 16 20:15:11 volumio go-librespot[2239]: time="2025-02-16T20:15:11+08:00" level=debug msg="obtained new client token: AABVaHbsteTKGIB46IQMF9rwciam6KvlSftQpkqcf3dnnvp1mtpkmaTyWRMeAs1MvdJRFKMTH1KAzEZkkh93szUp2c2bVnlDQ2NjWAINStUHDmgiqjL6AYu15AJkA8cHD/C83ZI0Nu0VfQOvgX95I76jBRwdby3RrIPxadweGIfCEduiGY4nnD7Z5YiYt5LVzrOzyZhdqEdBV5Udv1xKuA6wbw1HX96E9RHgkpa1BXSZxv9rUkHTK8yS1A7R" Feb 16 20:15:11 volumio go-librespot[2239]: time="2025-02-16T20:15:11+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 16 20:15:11 volumio go-librespot[2239]: time="2025-02-16T20:15:11+08:00" level=debug msg="completed keyexchange" Feb 16 20:15:11 volumio go-librespot[2239]: time="2025-02-16T20:15:11+08:00" level=debug msg="completed challenge" Feb 16 20:15:11 volumio go-librespot[2239]: time="2025-02-16T20:15:11+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 16 20:15:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 16 20:15:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 16 20:15:12 volumio volumio[984]: info: Initializing connection to go-librespot Websocket Feb 16 20:15:12 volumio volumio[984]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 16 20:15:14 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 16 20:15:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 580396. Feb 16 20:15:14 volumio systemd[1]: Stopped go-librespot Daemon. Feb 16 20:15:14 volumio systemd[1]: Started go-librespot Daemon. Feb 16 20:15:14 volumio go-librespot[2299]: Librespot-go daemon starting... Feb 16 20:15:14 volumio go-librespot[2299]: time="2025-02-16T20:15:14+08:00" level=info msg="generated new device id: 69425a23fc4e97e5ca91becd4459ad4205a18940" Feb 16 20:15:14 volumio go-librespot[2299]: time="2025-02-16T20:15:14+08:00" level=debug msg="stored credentials found for elvisbar" Feb 16 20:15:14 volumio go-librespot[2299]: time="2025-02-16T20:15:14+08:00" level=debug msg="obtained new client token: AAA55+k1DcaczpU5WhvAVtyk9IP6T89AeMt4tihmDvlsZNSZvSApm4nuoD+wSKJQhEPuO7+HafADKS0xToO8BRN/gJN9KwYiwMS17oaN1+jYsHFIqfq3vDasWOY47WCxPvSRro4Ql4vHF15wwDuEPTzbGM2Q3KgAnP1UgqBmpPSWhc3vaL2WyAPsSmESMJn6T0FIVySWlJ/iNPJUMpiz+FU3eX8nIR454bD3dc4F0ghsTLIi4s2QdhWnmJ94vSI=" Feb 16 20:15:15 volumio go-librespot[2299]: time="2025-02-16T20:15:15+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 16 20:15:15 volumio volumio[984]: info: Initializing connection to go-librespot Websocket Feb 16 20:15:15 volumio go-librespot[2299]: time="2025-02-16T20:15:15+08:00" level=debug msg="completed keyexchange" Feb 16 20:15:15 volumio go-librespot[2299]: time="2025-02-16T20:15:15+08:00" level=debug msg="new websocket client" Feb 16 20:15:15 volumio volumio[984]: info: Connection to go-librespot Websocket established Feb 16 20:15:15 volumio go-librespot[2299]: time="2025-02-16T20:15:15+08:00" level=debug msg="completed challenge" Feb 16 20:15:15 volumio go-librespot[2299]: time="2025-02-16T20:15:15+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 16 20:15:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 16 20:15:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 16 20:15:15 volumio volumio[984]: info: Connection to go-librespot Websocket closed Feb 16 20:15:18 volumio volumio[984]: info: Getting Spotify volume Feb 16 20:15:18 volumio volumio[984]: (node:984) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 16 20:15:18 volumio volumio[984]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Feb 16 20:15:18 volumio volumio[984]: (node:984) 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: 64818) Feb 16 20:15:18 volumio volumio[984]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Feb 16 20:15:18 volumio volumio[984]: info: CoreCommandRouter::volumioGetState Feb 16 20:15:18 volumio volumio[984]: info: CorePlayQueue::getTrack 6 Feb 16 20:15:18 volumio volumio[984]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Feb 16 20:15:18 volumio volumio[984]: info: Initializing connection to go-librespot Websocket Feb 16 20:15:18 volumio volumio[984]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 16 20:15:18 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 16 20:15:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 580397. Feb 16 20:15:18 volumio systemd[1]: Stopped go-librespot Daemon. Feb 16 20:15:18 volumio systemd[1]: Started go-librespot Daemon. Feb 16 20:15:18 volumio go-librespot[2311]: Librespot-go daemon starting... Feb 16 20:15:18 volumio go-librespot[2311]: time="2025-02-16T20:15:18+08:00" level=info msg="generated new device id: 04e04089f9169d89e04c09e50bf797338a1f9dbd" Feb 16 20:15:18 volumio go-librespot[2311]: time="2025-02-16T20:15:18+08:00" level=debug msg="stored credentials found for elvisbar" Feb 16 20:15:19 volumio go-librespot[2311]: time="2025-02-16T20:15:19+08:00" level=debug msg="obtained new client token: AAA/xvg9ndgaWLEynWrwaNMd7bDBKT5GTmcmykGahtFK8xuXinHWd4Z0GuKyOku9zRa0XzljhZ3fzD3PxHcd54z7mWBd4Nd5tfEOjEML8R6PeSxuV5y0VIMazCf3VXNqBZZqeMcV9ieRMm7vHPLhywj98fCGs8aYahWOHFkKGCW6ZmffYKZ/r/5KiTqT+jEwG8ZSla3hA3Ht+HShdgm5VnQSjAbLlTM70IGvA8R/2o/ejlGoUmdOIpMG6jfQgNY=" Feb 16 20:15:19 volumio go-librespot[2311]: time="2025-02-16T20:15:19+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 16 20:15:19 volumio go-librespot[2311]: time="2025-02-16T20:15:19+08:00" level=debug msg="completed keyexchange" Feb 16 20:15:19 volumio go-librespot[2311]: time="2025-02-16T20:15:19+08:00" level=debug msg="completed challenge" Feb 16 20:15:19 volumio go-librespot[2311]: time="2025-02-16T20:15:19+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 16 20:15:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 16 20:15:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 16 20:15:20 volumio volumio[984]: error: error Feb 16 20:15:21 volumio volumio[984]: info: Initializing connection to go-librespot Websocket Feb 16 20:15:21 volumio volumio[984]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 16 20:15:22 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 16 20:15:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 580398. Feb 16 20:15:22 volumio systemd[1]: Stopped go-librespot Daemon. Feb 16 20:15:22 volumio systemd[1]: Started go-librespot Daemon. Feb 16 20:15:22 volumio go-librespot[2333]: Librespot-go daemon starting... Feb 16 20:15:22 volumio go-librespot[2333]: time="2025-02-16T20:15:22+08:00" level=info msg="generated new device id: 297b5bce0cb6b6f895737988b4587bed4bcefe34" Feb 16 20:15:22 volumio go-librespot[2333]: time="2025-02-16T20:15:22+08:00" level=debug msg="stored credentials found for elvisbar" Feb 16 20:15:22 volumio go-librespot[2333]: time="2025-02-16T20:15:22+08:00" level=debug msg="obtained new client token: AAD6W70lF48RLPJoH2M7gGPMZmzh7sfSSSN4zqd1O+xb3ht/eIQHucKl7eeNQdPOARPtsUKRKa0amKOELtW5ePdMsI9z81W/7rg6EEJFIeAMEBeRmaGqCpf6QB2Sy7s/8ZhNbO1sb7F5D2w4WFmbBDljXC1tIJDfbSvyHOIamrv8OsQxlUBK7KG4yVzBezBWA9jPGo4GsaOYiFT3hoxGunqf524NvFnOq0zxukNvB1i279i8X51al32RCqSHssk=" Feb 16 20:15:23 volumio go-librespot[2333]: time="2025-02-16T20:15:23+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 16 20:15:23 volumio go-librespot[2333]: time="2025-02-16T20:15:23+08:00" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed dialing accesspoint: dial tcp 104.199.241.202:4070: connect: connection refused" Feb 16 20:15:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 16 20:15:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 16 20:15:24 volumio volumio[984]: info: Initializing connection to go-librespot Websocket Feb 16 20:15:24 volumio volumio[984]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 16 20:15:26 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 16 20:15:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 580399. Feb 16 20:15:26 volumio systemd[1]: Stopped go-librespot Daemon. Feb 16 20:15:26 volumio systemd[1]: Started go-librespot Daemon. Feb 16 20:15:26 volumio go-librespot[2345]: Librespot-go daemon starting... Feb 16 20:15:26 volumio go-librespot[2345]: time="2025-02-16T20:15:26+08:00" level=info msg="generated new device id: 7bdfc12a4c7fb948e5e0ebb7d1b7b53e9fba8a27" Feb 16 20:15:26 volumio go-librespot[2345]: time="2025-02-16T20:15:26+08:00" level=debug msg="stored credentials found for elvisbar" Feb 16 20:15:26 volumio go-librespot[2345]: time="2025-02-16T20:15:26+08:00" level=debug msg="obtained new client token: AADmjAdwtZM2JE7asR1INgdjhTX4OoJJyjr/8xo2Rxo0o5lJuI+zsf+K+kukX8NjBQB291+LKT2axzWFBtAEHpgbQRysBaPhyXC7xKgil50cMElX+Ol1STjwcJy7PHJ3AWc0B8wZ7mgrt8erpy/PaD03CkjpuSpIB1ZggfqxVJBkwSm3UxR5NR6E3FK2QuysCm3qMkyl/Y3J+TJ9h0/LMBslywTkr59VNj8hrk+ovXmPO1boAQNJcOSjvN3xY9g=" Feb 16 20:15:26 volumio go-librespot[2345]: time="2025-02-16T20:15:26+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 16 20:15:26 volumio go-librespot[2345]: time="2025-02-16T20:15:26+08:00" level=debug msg="completed keyexchange" Feb 16 20:15:27 volumio go-librespot[2345]: time="2025-02-16T20:15:27+08:00" level=debug msg="completed challenge" Feb 16 20:15:27 volumio go-librespot[2345]: time="2025-02-16T20:15:27+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 16 20:15:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 16 20:15:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 16 20:15:27 volumio volumio[984]: info: Initializing connection to go-librespot Websocket Feb 16 20:15:27 volumio volumio[984]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 16 20:15:30 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 16 20:15:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 580400. Feb 16 20:15:30 volumio systemd[1]: Stopped go-librespot Daemon. Feb 16 20:15:30 volumio systemd[1]: Started go-librespot Daemon. Feb 16 20:15:30 volumio go-librespot[2353]: Librespot-go daemon starting... Feb 16 20:15:30 volumio go-librespot[2353]: time="2025-02-16T20:15:30+08:00" level=info msg="generated new device id: 6c24373018f35b783470c61dde1c201a569267aa" Feb 16 20:15:30 volumio go-librespot[2353]: time="2025-02-16T20:15:30+08:00" level=debug msg="stored credentials found for elvisbar" Feb 16 20:15:30 volumio go-librespot[2353]: time="2025-02-16T20:15:30+08:00" level=debug msg="obtained new client token: AAChGlSt/EwkLkWoIZ5sHXkzHJqaKYYmkWA+E1AmH2mfjVZSUJyWL7T9vVF02Z0FfLJU0vyZj73kbgWO++W1m5/uZ7xV1vo+/43dzBlA950b0C2Tz3oQRplfSN4gvjVcLJvtf0+KHRfCy5QBVQxavIi2PRECg3it6SuNYklAy32o+D95+V+Orc6NEcCQbx0I8oliVo2eW0o9B0B/UesPm/6K3pnt/pQMAbp2ZgX4Ysp5hNJN3avqMVDiMuc0K8o=" Feb 16 20:15:30 volumio go-librespot[2353]: time="2025-02-16T20:15:30+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 16 20:15:30 volumio go-librespot[2353]: time="2025-02-16T20:15:30+08:00" level=debug msg="completed keyexchange" Feb 16 20:15:30 volumio volumio[984]: info: Initializing connection to go-librespot Websocket Feb 16 20:15:30 volumio volumio[984]: info: Connection to go-librespot Websocket established Feb 16 20:15:30 volumio go-librespot[2353]: time="2025-02-16T20:15:30+08:00" level=debug msg="new websocket client" Feb 16 20:15:31 volumio go-librespot[2353]: time="2025-02-16T20:15:31+08:00" level=debug msg="completed challenge" Feb 16 20:15:31 volumio go-librespot[2353]: time="2025-02-16T20:15:31+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 16 20:15:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 16 20:15:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 16 20:15:31 volumio volumio[984]: info: Connection to go-librespot Websocket closed Feb 16 20:15:33 volumio volumio[984]: info: Getting Spotify volume Feb 16 20:15:33 volumio volumio[984]: (node:984) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 16 20:15:33 volumio volumio[984]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Feb 16 20:15:33 volumio volumio[984]: (node:984) 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: 64819) Feb 16 20:15:33 volumio volumio[984]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Feb 16 20:15:33 volumio volumio[984]: info: CoreCommandRouter::volumioGetState Feb 16 20:15:33 volumio volumio[984]: info: CorePlayQueue::getTrack 6 Feb 16 20:15:33 volumio volumio[984]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Feb 16 20:15:34 volumio volumio[984]: info: Initializing connection to go-librespot Websocket Feb 16 20:15:34 volumio volumio[984]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 16 20:15:34 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 16 20:15:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 580401. Feb 16 20:15:34 volumio systemd[1]: Stopped go-librespot Daemon. Feb 16 20:15:34 volumio systemd[1]: Started go-librespot Daemon. Feb 16 20:15:34 volumio go-librespot[2375]: Librespot-go daemon starting... Feb 16 20:15:34 volumio go-librespot[2375]: time="2025-02-16T20:15:34+08:00" level=info msg="generated new device id: 9ea53cff9a081522c884ed595c8ef6570b1532f9" Feb 16 20:15:34 volumio go-librespot[2375]: time="2025-02-16T20:15:34+08:00" level=debug msg="stored credentials found for elvisbar" Feb 16 20:15:34 volumio go-librespot[2375]: time="2025-02-16T20:15:34+08:00" level=debug msg="obtained new client token: AAC4HAFSVTWx6gMf77Eg+nIRalb2jQH7D9vT9BkUpaBY3nyteNtgS9fM/NyFWMd9rGFBnROmUGmjtnhRyniy77CIvS0frndAEZlYSvT2IKL00rWMwxDDpMlOlu/ESTA4CZoi+96gOPJFQdtZGE9Jua4UpTAR20lkmnMxVyk2Mz2VGyRjtlcrJWQzYnKmUKPVNBayF/ci4r1Fa6b0aBczil1NAm4gqvSpnHrTKQf/lf+7jQxRTFxS8LUAtN8tPY4=" Feb 16 20:15:34 volumio go-librespot[2375]: time="2025-02-16T20:15:34+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 16 20:15:34 volumio go-librespot[2375]: time="2025-02-16T20:15:34+08:00" level=debug msg="completed keyexchange" Feb 16 20:15:35 volumio go-librespot[2375]: time="2025-02-16T20:15:35+08:00" level=debug msg="completed challenge" Feb 16 20:15:35 volumio go-librespot[2375]: time="2025-02-16T20:15:35+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 16 20:15:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 16 20:15:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 16 20:15:35 volumio volumio[984]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Feb 16 20:15:35 volumio volumio[984]: info: Preload queue cleared Feb 16 20:15:37 volumio volumio[984]: info: Initializing connection to go-librespot Websocket Feb 16 20:15:37 volumio volumio[984]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 16 20:15:37 volumio volumio[984]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Feb 16 20:15:38 volumio volumio[984]: info: Preload queue cleared Feb 16 20:15:38 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 16 20:15:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 580402. Feb 16 20:15:38 volumio systemd[1]: Stopped go-librespot Daemon. Feb 16 20:15:38 volumio systemd[1]: Started go-librespot Daemon. Feb 16 20:15:38 volumio go-librespot[2387]: Librespot-go daemon starting... Feb 16 20:15:38 volumio go-librespot[2387]: time="2025-02-16T20:15:38+08:00" level=info msg="generated new device id: 4a9e514613f64d85b7b97c680a2e701d4da8b33f" Feb 16 20:15:38 volumio go-librespot[2387]: time="2025-02-16T20:15:38+08:00" level=debug msg="stored credentials found for elvisbar" Feb 16 20:15:38 volumio go-librespot[2387]: time="2025-02-16T20:15:38+08:00" level=debug msg="obtained new client token: AAASd3KcwxgVZIZi5moRu7Zkmvu6/oFV/9HUs+Vy3CaOlvbn2FMLfStOzBwQr4KYyzO6sa2Yy1n5j+DHeftA7LhCvoSzGNz4QOf4/NfQX0ImxTFQ8ap+zr44slqudGbwEA7Hn+QCIEKIIsxzmht3m8rFUqZ348wNONRzkEqsW96BYH0e8qoL9v4adTK52J/NUAU/Hl47Z/z1oOUTw42Rxgtbd+3wIHo5I++I65o/6iMaIDfrl8/GsY/hS7de16k=" Feb 16 20:15:38 volumio go-librespot[2387]: time="2025-02-16T20:15:38+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 16 20:15:38 volumio go-librespot[2387]: time="2025-02-16T20:15:38+08:00" level=debug msg="completed keyexchange" Feb 16 20:15:39 volumio go-librespot[2387]: time="2025-02-16T20:15:39+08:00" level=debug msg="completed challenge" Feb 16 20:15:39 volumio go-librespot[2387]: time="2025-02-16T20:15:39+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 16 20:15:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 16 20:15:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 16 20:15:40 volumio volumio[984]: info: Initializing connection to go-librespot Websocket Feb 16 20:15:40 volumio volumio[984]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 16 20:15:40 volumio volumio[984]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 16 20:15:40 volumio volumio[984]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 16 20:15:40 volumio volumio[984]: info: Discovery: Getting this device information Feb 16 20:15:40 volumio volumio[984]: info: CoreCommandRouter::volumioGetState Feb 16 20:15:40 volumio volumio[984]: info: CorePlayQueue::getTrack 6 Feb 16 20:15:40 volumio volumio[984]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 16 20:15:42 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 16 20:15:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 580403. Feb 16 20:15:42 volumio systemd[1]: Stopped go-librespot Daemon. Feb 16 20:15:42 volumio systemd[1]: Started go-librespot Daemon. Feb 16 20:15:42 volumio go-librespot[2409]: Librespot-go daemon starting... Feb 16 20:15:42 volumio go-librespot[2409]: time="2025-02-16T20:15:42+08:00" level=info msg="generated new device id: f2316fde5ff76c490da2ae989c940951ac24f9dd" Feb 16 20:15:42 volumio go-librespot[2409]: time="2025-02-16T20:15:42+08:00" level=debug msg="stored credentials found for elvisbar" Feb 16 20:15:42 volumio go-librespot[2409]: time="2025-02-16T20:15:42+08:00" level=debug msg="obtained new client token: AACtqHAE++xLtFZbDqUvV0/I+YTRxnRqJ1oJYLXwOCb6whPBZ1A5No/WGSGBN0cFpxsvPhJrGM6XPUpWTXbNyfy6+8lS9ajsRwaD5CM4FG2JAUZMMkuWNZT6lY6iL61gAdoGdgsQm5F/raMKcB5+7MCA+nTrWtkzVTc3rb77phaSSkCjiwVYQ7+EnjnfV/evmlSCk4GR9jPasIc0+PBzy2GhBWVE9gVrAEYAwfnlA3i7HFgnaAFml340Lvpmvfs=" Feb 16 20:15:42 volumio go-librespot[2409]: time="2025-02-16T20:15:42+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 16 20:15:42 volumio go-librespot[2409]: time="2025-02-16T20:15:42+08:00" level=debug msg="completed keyexchange" Feb 16 20:15:43 volumio go-librespot[2409]: time="2025-02-16T20:15:43+08:00" level=debug msg="completed challenge" Feb 16 20:15:43 volumio go-librespot[2409]: time="2025-02-16T20:15:43+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 16 20:15:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 16 20:15:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 16 20:15:43 volumio volumio[984]: info: Initializing connection to go-librespot Websocket Feb 16 20:15:43 volumio volumio[984]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 16 20:15:46 volumio volumio[984]: info: Initializing connection to go-librespot Websocket Feb 16 20:15:46 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 16 20:15:46 volumio volumio[984]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 16 20:15:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 580404. Feb 16 20:15:46 volumio systemd[1]: Stopped go-librespot Daemon. Feb 16 20:15:46 volumio systemd[1]: Started go-librespot Daemon. Feb 16 20:15:46 volumio go-librespot[2418]: Librespot-go daemon starting... Feb 16 20:15:46 volumio go-librespot[2418]: time="2025-02-16T20:15:46+08:00" level=info msg="generated new device id: 9bfc9008e0865638b1af48a1dacb94beb00ddf16" Feb 16 20:15:46 volumio go-librespot[2418]: time="2025-02-16T20:15:46+08:00" level=debug msg="stored credentials found for elvisbar" Feb 16 20:15:46 volumio go-librespot[2418]: time="2025-02-16T20:15:46+08:00" level=debug msg="obtained new client token: AACyZZmaWc8AwmwKoH4O+Zzvs3W8ZSymYLk5H/mpkprIJqrx6/ELJC1s2efxJhzJTKT/lqSlIRyEY9+b34h3rTd6kvzkPRRz/TZgodloW8+yvthm8Jk5rOZtpU/v0KFQDQxb6zdRSCdZiO0w2RcmtP6ZjoMB4HiYp7i1dWDc1Sw0u7vws3UnCSeh8Wvu/ckPWydUbkv29muj+dA3kgSjyy0vJ5rhwvvTX5xD3ZP7E22zJD9EfI8MLWOVgcmeAWE=" Feb 16 20:15:46 volumio go-librespot[2418]: time="2025-02-16T20:15:46+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 16 20:15:46 volumio go-librespot[2418]: time="2025-02-16T20:15:46+08:00" level=debug msg="completed keyexchange" Feb 16 20:15:46 volumio go-librespot[2418]: time="2025-02-16T20:15:46+08:00" level=debug msg="completed challenge" Feb 16 20:15:46 volumio go-librespot[2418]: time="2025-02-16T20:15:46+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 16 20:15:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 16 20:15:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 16 20:15:48 volumio volumio[984]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Feb 16 20:15:48 volumio volumio[984]: info: Preload queue cleared Feb 16 20:15:49 volumio volumio[984]: info: Initializing connection to go-librespot Websocket Feb 16 20:15:49 volumio volumio[984]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 16 20:15:50 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 16 20:15:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 580405. Feb 16 20:15:50 volumio systemd[1]: Stopped go-librespot Daemon. Feb 16 20:15:50 volumio systemd[1]: Started go-librespot Daemon. Feb 16 20:15:50 volumio go-librespot[2429]: Librespot-go daemon starting... Feb 16 20:15:50 volumio go-librespot[2429]: time="2025-02-16T20:15:50+08:00" level=info msg="generated new device id: 6142f787dd2ba41af23fb4328ed924d4e431de8f" Feb 16 20:15:50 volumio go-librespot[2429]: time="2025-02-16T20:15:50+08:00" level=debug msg="stored credentials found for elvisbar" Feb 16 20:15:50 volumio go-librespot[2429]: time="2025-02-16T20:15:50+08:00" level=debug msg="obtained new client token: AADnDFizUfDGArtovLB0GPvus1+Ew6PAyKf05i5m0GDoaownAx9J1hdWgEQLIZN2UJRdZjZSDnHjLWGSCL8hUwsHz9DzPpCLcSKb5gvNwbAq/MnX90c0USfxyAevNizMHikh0VOQmWrEfCwZ0po80nB6OmwqPUb82d3W9Mv1X+EvpXFKgNExOG4G1q/MZnxqiiEaHE5MzZdIkb4Q+kcuA+Cs44SyhUE+K6/vt4wkyeFsCLmuEgnW22gZBdl6" Feb 16 20:15:50 volumio go-librespot[2429]: time="2025-02-16T20:15:50+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 16 20:15:50 volumio go-librespot[2429]: time="2025-02-16T20:15:50+08:00" level=debug msg="completed keyexchange" Feb 16 20:15:50 volumio go-librespot[2429]: time="2025-02-16T20:15:50+08:00" level=debug msg="completed challenge" Feb 16 20:15:50 volumio go-librespot[2429]: time="2025-02-16T20:15:50+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 16 20:15:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 16 20:15:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 16 20:15:52 volumio volumio[984]: info: Initializing connection to go-librespot Websocket Feb 16 20:15:52 volumio volumio[984]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 16 20:15:54 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 16 20:15:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 580406. Feb 16 20:15:54 volumio systemd[1]: Stopped go-librespot Daemon. Feb 16 20:15:54 volumio systemd[1]: Started go-librespot Daemon. Feb 16 20:15:54 volumio go-librespot[2452]: Librespot-go daemon starting... Feb 16 20:15:54 volumio go-librespot[2452]: time="2025-02-16T20:15:54+08:00" level=info msg="generated new device id: c2c3f2b9e4390e7e3710cb5c3a9e59689363b082" Feb 16 20:15:54 volumio go-librespot[2452]: time="2025-02-16T20:15:54+08:00" level=debug msg="stored credentials found for elvisbar" Feb 16 20:15:54 volumio go-librespot[2452]: time="2025-02-16T20:15:54+08:00" level=debug msg="obtained new client token: AADIMmemEECMn2lzAiylYyg9mfsthLNv1Zxv+LbodhmsS5ABR1XAnOMXMEhbilc8E0sFb42UWwruVlIGss3MQdJVHTAdaALQ3/G0+HlXzEJixhpN3iF84niKmj2O5dcORd+931TKeluAU7ogLlvcYIVgUTrMm8TzQhX3wC6f7/YVay4byv/eWv0LKNB7+C/LPmM2zNDGUMYpTL3URUVaIP96BmCo2twuQWT9QhEI+ZAxhkSTqgMttpwwC12R" Feb 16 20:15:54 volumio go-librespot[2452]: time="2025-02-16T20:15:54+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 16 20:15:54 volumio go-librespot[2452]: time="2025-02-16T20:15:54+08:00" level=debug msg="completed keyexchange" Feb 16 20:15:54 volumio go-librespot[2452]: time="2025-02-16T20:15:54+08:00" level=debug msg="completed challenge" Feb 16 20:15:54 volumio go-librespot[2452]: time="2025-02-16T20:15:54+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 16 20:15:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 16 20:15:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 16 20:15:55 volumio volumio[984]: info: Initializing connection to go-librespot Websocket Feb 16 20:15:55 volumio volumio[984]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 16 20:15:58 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 16 20:15:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 580407. Feb 16 20:15:58 volumio systemd[1]: Stopped go-librespot Daemon. Feb 16 20:15:58 volumio systemd[1]: Started go-librespot Daemon. Feb 16 20:15:58 volumio go-librespot[2463]: Librespot-go daemon starting... Feb 16 20:15:58 volumio go-librespot[2463]: time="2025-02-16T20:15:58+08:00" level=info msg="generated new device id: 25434cd8b8c719104f3f4b1231046f213fcfcc99" Feb 16 20:15:58 volumio go-librespot[2463]: time="2025-02-16T20:15:58+08:00" level=debug msg="stored credentials found for elvisbar" Feb 16 20:15:58 volumio volumio[984]: info: Initializing connection to go-librespot Websocket Feb 16 20:15:58 volumio go-librespot[2463]: time="2025-02-16T20:15:58+08:00" level=debug msg="new websocket client" Feb 16 20:15:58 volumio volumio[984]: info: Connection to go-librespot Websocket established Feb 16 20:15:58 volumio go-librespot[2463]: time="2025-02-16T20:15:58+08:00" level=debug msg="obtained new client token: AACrsrRLEc3zdysB8Y6Ecf1leNtlzfY0TXYd+SeU+kr4MArVzLJl9hLvHY08V2IpnMxj1+xZjI/LBk/YZTAOnVmPsOVtsSjr26PD0MoQ9iCn4IPeumGsZiL5IP3N1qlrmz8At1AbP6Ui3XaXDIbQLM1fQXHFWZkJgK+vOc60yhjTj0izbDUSQ+8Jvt2qM+lt6ippP/quVVp+NKkLG0rz3ACCVKag/4YqfTA2JRjWQJne8MXAaNNXry0r4MJu" Feb 16 20:15:58 volumio go-librespot[2463]: time="2025-02-16T20:15:58+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 16 20:15:58 volumio go-librespot[2463]: time="2025-02-16T20:15:58+08:00" level=debug msg="completed keyexchange" Feb 16 20:15:58 volumio go-librespot[2463]: time="2025-02-16T20:15:58+08:00" level=debug msg="completed challenge" Feb 16 20:15:58 volumio go-librespot[2463]: time="2025-02-16T20:15:58+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 16 20:15:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 16 20:15:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 16 20:15:58 volumio volumio[984]: info: Connection to go-librespot Websocket closed Feb 16 20:16:01 volumio volumio[984]: info: Getting Spotify volume Feb 16 20:16:01 volumio volumio[984]: (node:984) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 16 20:16:01 volumio volumio[984]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Feb 16 20:16:01 volumio volumio[984]: (node:984) 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: 64820) Feb 16 20:16:01 volumio volumio[984]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Feb 16 20:16:01 volumio volumio[984]: info: CoreCommandRouter::volumioGetState Feb 16 20:16:01 volumio volumio[984]: info: CorePlayQueue::getTrack 6 Feb 16 20:16:01 volumio volumio[984]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Feb 16 20:16:01 volumio volumio[984]: info: Initializing connection to go-librespot Websocket Feb 16 20:16:01 volumio volumio[984]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 16 20:16:02 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 16 20:16:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 580408. Feb 16 20:16:02 volumio systemd[1]: Stopped go-librespot Daemon. Feb 16 20:16:02 volumio systemd[1]: Started go-librespot Daemon. Feb 16 20:16:02 volumio go-librespot[2486]: Librespot-go daemon starting... Feb 16 20:16:02 volumio go-librespot[2486]: time="2025-02-16T20:16:02+08:00" level=info msg="generated new device id: 6dbf8b4411ceadb81393a9fe03cf09b6b8b955c5" Feb 16 20:16:02 volumio go-librespot[2486]: time="2025-02-16T20:16:02+08:00" level=debug msg="stored credentials found for elvisbar" Feb 16 20:16:02 volumio go-librespot[2486]: time="2025-02-16T20:16:02+08:00" level=debug msg="obtained new client token: AACMI43Zvl+VV6SlpCmF+bW0nRjT61TCu5wxy7r9l9DilObA+b8LF0S1QemP7JGmk6TnEHlZMFmicumqcOW4vN0Yc0NGAI7FCJfoFpFvjdFI9XofbnjEEJ6s1/pCOluKKqe92Jmr7P5ALbfkM0Uej9FKh2cld6LZkX/TTPJfT0RNxPPmF1hKqwcFwFliuulCBwCSqPdNUG/iiIMN++kMhA+u8ibL2I36VI6ic5fdt+kQNhkcUI7rRuhJf5+6" Feb 16 20:16:02 volumio go-librespot[2486]: time="2025-02-16T20:16:02+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 16 20:16:02 volumio go-librespot[2486]: time="2025-02-16T20:16:02+08:00" level=debug msg="completed keyexchange" Feb 16 20:16:02 volumio go-librespot[2486]: time="2025-02-16T20:16:02+08:00" level=debug msg="completed challenge" Feb 16 20:16:02 volumio go-librespot[2486]: time="2025-02-16T20:16:02+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 16 20:16:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 16 20:16:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 16 20:16:04 volumio volumio[984]: info: Initializing connection to go-librespot Websocket Feb 16 20:16:04 volumio volumio[984]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 16 20:16:05 volumio volumio[984]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Feb 16 20:16:06 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 16 20:16:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 580409. Feb 16 20:16:06 volumio systemd[1]: Stopped go-librespot Daemon. Feb 16 20:16:06 volumio systemd[1]: Started go-librespot Daemon. Feb 16 20:16:06 volumio go-librespot[2495]: Librespot-go daemon starting... Feb 16 20:16:06 volumio go-librespot[2495]: time="2025-02-16T20:16:06+08:00" level=info msg="generated new device id: c177d50e4a8648307bd1042bd9cfe53544faf20b" Feb 16 20:16:06 volumio go-librespot[2495]: time="2025-02-16T20:16:06+08:00" level=debug msg="stored credentials found for elvisbar" Feb 16 20:16:06 volumio go-librespot[2495]: time="2025-02-16T20:16:06+08:00" level=debug msg="obtained new client token: AADTz0dwpqr0HV0BfuX7sYCtHRXsAU8ysej5S45OnT2ITeSPczOWvEAXtvoim+rw299gAJhRugf8cgUWx52ksfBwmae9BBusmNm5mRJHNwkUf5ZahVgtteWeqEI4kmC23gZlY+pdylYdQ3KFw5N0qpF/o2zbsiiItTdffdPwwt1cSFtN8HwQYdNzKhhe6NhDBgF4DGriDyYHebO+MLUY+gVWrpplY/UxxJHOxFn5rEJueTeH5HDq5mlwrBQ9" Feb 16 20:16:06 volumio go-librespot[2495]: time="2025-02-16T20:16:06+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 16 20:16:06 volumio go-librespot[2495]: time="2025-02-16T20:16:06+08:00" level=debug msg="completed keyexchange" Feb 16 20:16:06 volumio volumio[984]: info: Preload queue cleared Feb 16 20:16:06 volumio go-librespot[2495]: time="2025-02-16T20:16:06+08:00" level=debug msg="completed challenge" Feb 16 20:16:06 volumio go-librespot[2495]: time="2025-02-16T20:16:06+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 16 20:16:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 16 20:16:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 16 20:16:07 volumio volumio[984]: info: Initializing connection to go-librespot Websocket Feb 16 20:16:07 volumio volumio[984]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 16 20:16:10 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 16 20:16:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 580410. Feb 16 20:16:10 volumio systemd[1]: Stopped go-librespot Daemon. Feb 16 20:16:10 volumio systemd[1]: Started go-librespot Daemon. Feb 16 20:16:10 volumio go-librespot[2506]: Librespot-go daemon starting... Feb 16 20:16:10 volumio go-librespot[2506]: time="2025-02-16T20:16:10+08:00" level=info msg="generated new device id: d6879a38a9bf164abf2d04a6b6c9b662fc6b5459" Feb 16 20:16:10 volumio go-librespot[2506]: time="2025-02-16T20:16:10+08:00" level=debug msg="stored credentials found for elvisbar" Feb 16 20:16:10 volumio go-librespot[2506]: time="2025-02-16T20:16:10+08:00" level=debug msg="obtained new client token: AAAJNDGRlxD2ErmhStvQ7x7aCwI1i38BBKI2b2pG3ui+ByhynYg854ZWup99749F+5tE6YCosVuonrBOXGA9yZI9EkC0DcvIvj5SvSQ6DvMOx04/rl4euAAnGBFtcfJ1S2kz4YjtKAc6PXkZvQZlYDHIJyR+jdQ6bdo7zaZ3IACp9Khii3XRkqy5uUSMxD5X063nd1UdQmjF613ieJwrPxodIlKweMNSvX90qSrYjQb+xtbEdsc++Go0h9gf" Feb 16 20:16:10 volumio go-librespot[2506]: time="2025-02-16T20:16:10+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 16 20:16:10 volumio go-librespot[2506]: time="2025-02-16T20:16:10+08:00" level=debug msg="completed keyexchange" Feb 16 20:16:10 volumio volumio[984]: error: error Feb 16 20:16:10 volumio go-librespot[2506]: time="2025-02-16T20:16:10+08:00" level=debug msg="completed challenge" Feb 16 20:16:10 volumio go-librespot[2506]: time="2025-02-16T20:16:10+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 16 20:16:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 16 20:16:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 16 20:16:10 volumio volumio[984]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 16 20:16:10 volumio volumio[984]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 16 20:16:10 volumio volumio[984]: info: Discovery: Getting this device information Feb 16 20:16:10 volumio volumio[984]: info: CoreCommandRouter::volumioGetState Feb 16 20:16:10 volumio volumio[984]: info: CorePlayQueue::getTrack 6 Feb 16 20:16:10 volumio volumio[984]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 16 20:16:10 volumio volumio[984]: info: Initializing connection to go-librespot Websocket Feb 16 20:16:10 volumio volumio[984]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 16 20:16:13 volumio volumio[984]: info: Initializing connection to go-librespot Websocket Feb 16 20:16:13 volumio volumio[984]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 16 20:16:13 volumio volumio[984]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Feb 16 20:16:14 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 16 20:16:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 580411. Feb 16 20:16:14 volumio systemd[1]: Stopped go-librespot Daemon. Feb 16 20:16:14 volumio systemd[1]: Started go-librespot Daemon. Feb 16 20:16:14 volumio go-librespot[2528]: Librespot-go daemon starting... Feb 16 20:16:14 volumio go-librespot[2528]: time="2025-02-16T20:16:14+08:00" level=info msg="generated new device id: 67f7643bdf3a4b867b96a0a6e829758379a4d5d8" Feb 16 20:16:14 volumio go-librespot[2528]: time="2025-02-16T20:16:14+08:00" level=debug msg="stored credentials found for elvisbar" Feb 16 20:16:14 volumio go-librespot[2528]: time="2025-02-16T20:16:14+08:00" level=debug msg="obtained new client token: AAA2NhqGlZxybc7n4AVkK/qXxtKN0b7wkgbHxEyxYGZnoMcYzYuYVdHT65qznzKXVMvg1Ir/0MQlNpsCBMs24pu7FQ0pWe+CpA6t2KbQhVboLq+MrGdcjyv0d5tYqBgwXTCtRc5l+O/rzsIbiPRk8K30PrPToGtDyi0RpgbnFwSQfC8fP8uZADRvND8pjLLAgzg9MEvETwI2Iy4+3cE7VJ56mUDu16Co/L+k7TQISrlxGDN8sn1TskJ3b5ya" Feb 16 20:16:14 volumio volumio[984]: info: Preload queue cleared Feb 16 20:16:14 volumio volumio[984]: info: Preloading song: upnp/http://192.168.0.127:32469/ContentDirectory/1609f65c-ecd9-e401-9f4c-4a2633e08935/control.xml@07783c26470a10174fef Feb 16 20:16:14 volumio volumio[984]: info: Preloading song: upnp/http://192.168.0.127:32469/ContentDirectory/1609f65c-ecd9-e401-9f4c-4a2633e08935/control.xml@53bb655928836ffa1da3 Feb 16 20:16:14 volumio volumio[984]: info: Preloading song: upnp/http://192.168.0.127:32469/ContentDirectory/1609f65c-ecd9-e401-9f4c-4a2633e08935/control.xml@439942e6be26c19830b1 Feb 16 20:16:14 volumio volumio[984]: info: Preloading song: upnp/http://192.168.0.127:32469/ContentDirectory/1609f65c-ecd9-e401-9f4c-4a2633e08935/control.xml@b4e26b7eeee6ae3f93b4 Feb 16 20:16:14 volumio volumio[984]: info: Preloading song: upnp/http://192.168.0.127:32469/ContentDirectory/1609f65c-ecd9-e401-9f4c-4a2633e08935/control.xml@cfd4bb872ff444247d2a Feb 16 20:16:14 volumio volumio[984]: info: Preloading song: upnp/http://192.168.0.127:32469/ContentDirectory/1609f65c-ecd9-e401-9f4c-4a2633e08935/control.xml@07a4d0918f19d5da8295 Feb 16 20:16:14 volumio volumio[984]: info: Preloading song: upnp/http://192.168.0.127:32469/ContentDirectory/1609f65c-ecd9-e401-9f4c-4a2633e08935/control.xml@96eca95cf1b761e14fad Feb 16 20:16:14 volumio volumio[984]: info: Preloading song: upnp/http://192.168.0.127:32469/ContentDirectory/1609f65c-ecd9-e401-9f4c-4a2633e08935/control.xml@ca66ff19592e07922772 Feb 16 20:16:14 volumio go-librespot[2528]: time="2025-02-16T20:16:14+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 16 20:16:14 volumio volumio[984]: info: Exploding uri upnp/http://192.168.0.127:32469/ContentDirectory/1609f65c-ecd9-e401-9f4c-4a2633e08935/control.xml@07783c26470a10174fef in service upnp_browser Feb 16 20:16:14 volumio go-librespot[2528]: time="2025-02-16T20:16:14+08:00" level=debug msg="completed keyexchange" Feb 16 20:16:14 volumio volumio[984]: info: Exploding uri upnp/http://192.168.0.127:32469/ContentDirectory/1609f65c-ecd9-e401-9f4c-4a2633e08935/control.xml@53bb655928836ffa1da3 in service upnp_browser Feb 16 20:16:14 volumio volumio[984]: info: Exploding uri upnp/http://192.168.0.127:32469/ContentDirectory/1609f65c-ecd9-e401-9f4c-4a2633e08935/control.xml@439942e6be26c19830b1 in service upnp_browser Feb 16 20:16:14 volumio volumio[984]: info: Exploding uri upnp/http://192.168.0.127:32469/ContentDirectory/1609f65c-ecd9-e401-9f4c-4a2633e08935/control.xml@b4e26b7eeee6ae3f93b4 in service upnp_browser Feb 16 20:16:14 volumio volumio[984]: info: Exploding uri upnp/http://192.168.0.127:32469/ContentDirectory/1609f65c-ecd9-e401-9f4c-4a2633e08935/control.xml@cfd4bb872ff444247d2a in service upnp_browser Feb 16 20:16:14 volumio volumio[984]: info: Exploding uri upnp/http://192.168.0.127:32469/ContentDirectory/1609f65c-ecd9-e401-9f4c-4a2633e08935/control.xml@07a4d0918f19d5da8295 in service upnp_browser Feb 16 20:16:14 volumio volumio[984]: info: Exploding uri upnp/http://192.168.0.127:32469/ContentDirectory/1609f65c-ecd9-e401-9f4c-4a2633e08935/control.xml@96eca95cf1b761e14fad in service upnp_browser Feb 16 20:16:14 volumio volumio[984]: info: Exploding uri upnp/http://192.168.0.127:32469/ContentDirectory/1609f65c-ecd9-e401-9f4c-4a2633e08935/control.xml@ca66ff19592e07922772 in service upnp_browser Feb 16 20:16:14 volumio go-librespot[2528]: time="2025-02-16T20:16:14+08:00" level=debug msg="completed challenge" Feb 16 20:16:14 volumio go-librespot[2528]: time="2025-02-16T20:16:14+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 16 20:16:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 16 20:16:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 16 20:16:16 volumio volumio[984]: info: Initializing connection to go-librespot Websocket Feb 16 20:16:16 volumio volumio[984]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 16 20:16:18 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 16 20:16:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 580412. Feb 16 20:16:18 volumio systemd[1]: Stopped go-librespot Daemon. Feb 16 20:16:18 volumio systemd[1]: Started go-librespot Daemon. Feb 16 20:16:18 volumio go-librespot[2577]: Librespot-go daemon starting... Feb 16 20:16:18 volumio go-librespot[2577]: time="2025-02-16T20:16:18+08:00" level=info msg="generated new device id: 9dce225242c20ff635fc99e967ee438cbfd300c8" Feb 16 20:16:18 volumio go-librespot[2577]: time="2025-02-16T20:16:18+08:00" level=debug msg="stored credentials found for elvisbar" Feb 16 20:16:18 volumio go-librespot[2577]: time="2025-02-16T20:16:18+08:00" level=debug msg="obtained new client token: AAAs2UrJcOAbxTSBBO89ATYtESTEVxgFgZY/WC2bBhC8WR/lwq568bliXMIicZ5EpY7B69S051oRqMZp1ON8nJgZXA88rSXoExlyXygjtcpXlVMELICJZaxAG1FayXk2lWZvvpg+w/uxCvmTpAjK7cdIZRp19Kc2E36aaiKb4EigyC0FpMC1NZV3SUIPd8X4eLrT5VQpwk4evW/YcM86Zfxlka4GqH18GCRUXgTKPHnaItKTHXvn2b5dusQx" Feb 16 20:16:18 volumio go-librespot[2577]: time="2025-02-16T20:16:18+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 16 20:16:18 volumio go-librespot[2577]: time="2025-02-16T20:16:18+08:00" level=debug msg="completed keyexchange" Feb 16 20:16:18 volumio go-librespot[2577]: time="2025-02-16T20:16:18+08:00" level=debug msg="completed challenge" Feb 16 20:16:18 volumio go-librespot[2577]: time="2025-02-16T20:16:18+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 16 20:16:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 16 20:16:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 16 20:16:19 volumio volumio[984]: info: Initializing connection to go-librespot Websocket Feb 16 20:16:19 volumio volumio[984]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 16 20:16:22 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 16 20:16:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 580413. Feb 16 20:16:22 volumio systemd[1]: Stopped go-librespot Daemon. Feb 16 20:16:22 volumio systemd[1]: Started go-librespot Daemon. Feb 16 20:16:22 volumio go-librespot[2599]: Librespot-go daemon starting... Feb 16 20:16:22 volumio go-librespot[2599]: time="2025-02-16T20:16:22+08:00" level=info msg="generated new device id: 2e226a354fa237d95c01fe1288f111329fc35cbb" Feb 16 20:16:22 volumio go-librespot[2599]: time="2025-02-16T20:16:22+08:00" level=debug msg="stored credentials found for elvisbar" Feb 16 20:16:22 volumio go-librespot[2599]: time="2025-02-16T20:16:22+08:00" level=debug msg="obtained new client token: AABiDOE4+ZxCqtv9UN884O9Ulhb8IrVQJE/S1gof4i6pJPZwJ6My8JDmQBCTLABMzsYTJ+QGAQJKx6Gf2oQekY621aIanBqYmIwB3ymBTlpi6dkslLOl5TiFVU8HtUwnHQXEnkMYHkXRZ1knSx6Ftgm9jcuQg5hG5XHtSUOL2hH9ZwY+IjBRzFQ0jJqDSS/uOZN/jLDKE/pX3FsKjXwxdkJ70S/cOTySjHBF9oDFIxAk8yWbBbAILEyGqPFh" Feb 16 20:16:22 volumio go-librespot[2599]: time="2025-02-16T20:16:22+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 16 20:16:22 volumio go-librespot[2599]: time="2025-02-16T20:16:22+08:00" level=debug msg="completed keyexchange" Feb 16 20:16:22 volumio go-librespot[2599]: time="2025-02-16T20:16:22+08:00" level=debug msg="completed challenge" Feb 16 20:16:22 volumio go-librespot[2599]: time="2025-02-16T20:16:22+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 16 20:16:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 16 20:16:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 16 20:16:22 volumio volumio[984]: info: Initializing connection to go-librespot Websocket Feb 16 20:16:22 volumio volumio[984]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 16 20:16:24 volumio volumio[984]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Feb 16 20:16:24 volumio volumio[984]: info: Preload queue cleared Feb 16 20:16:25 volumio volumio[984]: info: Initializing connection to go-librespot Websocket Feb 16 20:16:25 volumio volumio[984]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 16 20:16:26 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 16 20:16:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 580414. Feb 16 20:16:26 volumio systemd[1]: Stopped go-librespot Daemon. Feb 16 20:16:26 volumio systemd[1]: Started go-librespot Daemon. Feb 16 20:16:26 volumio go-librespot[2608]: Librespot-go daemon starting... Feb 16 20:16:26 volumio go-librespot[2608]: time="2025-02-16T20:16:26+08:00" level=info msg="generated new device id: 9903c35e10ba920b7243b927aedf6b88b1d364dc" Feb 16 20:16:26 volumio go-librespot[2608]: time="2025-02-16T20:16:26+08:00" level=debug msg="stored credentials found for elvisbar" Feb 16 20:16:26 volumio go-librespot[2608]: time="2025-02-16T20:16:26+08:00" level=debug msg="obtained new client token: AAAddyXqm8ZwZ2BXkrYP53if7+fx7MZ+vtoZKF5ok5OntnXqaPnFv1yEyX5jqv7niCA1CoNU8YAFYfKrRApxQ09/b/5EwWhiCqufEyRvdWqLi4FIKezyES+nZJLaxgB+0HH3HVzfPnsmB3DPAb5DixRuSuqGszUVUkfmF0aqzkrBRTrZNaNtHiYL2ylcI7koiPcJDjoOelRCSHfmTvJF9rq0sNQJxNwV/0UXSWuwF+jufd8HYI3NrN4Kg8iW" Feb 16 20:16:26 volumio go-librespot[2608]: time="2025-02-16T20:16:26+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 16 20:16:26 volumio go-librespot[2608]: time="2025-02-16T20:16:26+08:00" level=debug msg="completed keyexchange" Feb 16 20:16:26 volumio go-librespot[2608]: time="2025-02-16T20:16:26+08:00" level=debug msg="completed challenge" Feb 16 20:16:26 volumio go-librespot[2608]: time="2025-02-16T20:16:26+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 16 20:16:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 16 20:16:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 16 20:16:27 volumio volumio[984]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Feb 16 20:16:28 volumio volumio[984]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 16 20:16:28 volumio volumio[984]: TypeError: Cannot read property 'length' of undefined Feb 16 20:16:28 volumio volumio[984]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Feb 16 20:16:28 volumio volumio[984]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Feb 16 20:16:28 volumio volumio[984]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Feb 16 20:16:28 volumio volumio[984]: at Parser.emit (events.js:315:20) Feb 16 20:16:28 volumio volumio[984]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Feb 16 20:16:28 volumio volumio[984]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Feb 16 20:16:28 volumio volumio[984]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Feb 16 20:16:28 volumio volumio[984]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Feb 16 20:16:28 volumio volumio[984]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Feb 16 20:16:28 volumio volumio[984]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Feb 16 20:16:28 volumio volumio[984]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Feb 16 20:16:28 volumio volumio[984]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Feb 16 20:16:28 volumio volumio[984]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Feb 16 20:16:28 volumio volumio[984]: at IncomingMessage.emit (events.js:327:22) Feb 16 20:16:28 volumio volumio[984]: at endReadableNT (internal/streams/readable.js:1327:12) Feb 16 20:16:28 volumio volumio[984]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Feb 16 20:16:28 volumio volumio[984]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 16 20:16:29 volumio sudo[2628]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-02-16 20:15 Feb 16 20:16:29 volumio sudo[2628]: 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="f6610a1100d2380eef33bd3004af43153c786f96" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="1c0e5daee99fe3a72cc38b0d1fe6cd78d7f001fe" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 16 Dec 2024 09:30:04 AM CET" VOLUMIO_VERSION="3.785" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fe0ac4b79aed19ccde4b5bd83d468193"