-- Logs begin at Thu 2019-02-14 12:11:59 EET, end at Tue 2024-10-01 22:32:10 EEST. -- Oct 01 22:31:00 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Oct 01 22:31:00 volumio volumio[898]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 01 22:31:02 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 01 22:31:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 746. Oct 01 22:31:02 volumio systemd[1]: Stopped go-librespot Daemon. Oct 01 22:31:02 volumio systemd[1]: Started go-librespot Daemon. Oct 01 22:31:02 volumio go-librespot[11264]: Librespot-go daemon starting... Oct 01 22:31:02 volumio go-librespot[11264]: time="2024-10-01T22:31:02+03:00" level=info msg="generated new device id: 22b80b768d4ba476f246133e86daa2445ddab013" Oct 01 22:31:02 volumio go-librespot[11264]: time="2024-10-01T22:31:02+03:00" level=debug msg="stored credentials found for 322996" Oct 01 22:31:02 volumio go-librespot[11264]: time="2024-10-01T22:31:02+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Oct 01 22:31:02 volumio go-librespot[11264]: time="2024-10-01T22:31:02+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 01 22:31:02 volumio go-librespot[11264]: time="2024-10-01T22:31:02+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 01 22:31:02 volumio go-librespot[11264]: time="2024-10-01T22:31:02+03:00" level=debug msg="zeroconf server listening on port 36921" Oct 01 22:31:02 volumio kernel: hwmon hwmon1: Undervoltage detected! Oct 01 22:31:02 volumio go-librespot[11264]: time="2024-10-01T22:31:02+03:00" level=debug msg="obtained new client token: AACsFxbAfs7BeMGwFu18VBSVX9YopN6eBQFcWbLSZkcGcgUBDaetcaZg3M2o8NR4i40AaOLpT8GvIBImDZ8v+pSZo2kZGJdzcHLXMA6r5WWCva+HtOEHOhq0FCo4QdHUPTFSQXy0N12SDFkIpt/8+UsEaiVs7pGw5cPiO6Dh/LIIacUm6diTASWTpfmdV3UzR/OKguzESPi7ZpIrezVMK+rHuXVogszrRYzZWjVIvVl4wHkOW2QbggMwbA==" Oct 01 22:31:02 volumio go-librespot[11264]: time="2024-10-01T22:31:02+03:00" level=debug msg="completed keyexchange" Oct 01 22:31:02 volumio go-librespot[11264]: time="2024-10-01T22:31:02+03:00" level=debug msg="completed challenge" Oct 01 22:31:03 volumio go-librespot[11264]: time="2024-10-01T22:31:03+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 01 22:31:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 01 22:31:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 01 22:31:03 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Oct 01 22:31:03 volumio volumio[898]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 01 22:31:06 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 01 22:31:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 747. Oct 01 22:31:06 volumio systemd[1]: Stopped go-librespot Daemon. Oct 01 22:31:06 volumio systemd[1]: Started go-librespot Daemon. Oct 01 22:31:06 volumio go-librespot[11275]: Librespot-go daemon starting... Oct 01 22:31:06 volumio go-librespot[11275]: time="2024-10-01T22:31:06+03:00" level=info msg="generated new device id: d67ae80b8bb198948c8d36453d7e8f08d64b74bd" Oct 01 22:31:06 volumio go-librespot[11275]: time="2024-10-01T22:31:06+03:00" level=debug msg="stored credentials found for 322996" Oct 01 22:31:06 volumio go-librespot[11275]: time="2024-10-01T22:31:06+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Oct 01 22:31:06 volumio go-librespot[11275]: time="2024-10-01T22:31:06+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 01 22:31:06 volumio go-librespot[11275]: time="2024-10-01T22:31:06+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 01 22:31:06 volumio go-librespot[11275]: time="2024-10-01T22:31:06+03:00" level=debug msg="zeroconf server listening on port 42153" Oct 01 22:31:06 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Oct 01 22:31:06 volumio go-librespot[11275]: time="2024-10-01T22:31:06+03:00" level=debug msg="new websocket client" Oct 01 22:31:06 volumio volumio[898]: info: Connection to go-librespot Websocket established Oct 01 22:31:06 volumio go-librespot[11275]: time="2024-10-01T22:31:06+03:00" level=debug msg="obtained new client token: AAAAwX7G0ozDdwfye94lVmM4L8GUCL2bQCRnGRsLlATX6gfVjs1tgGulRSj3hRF9ZK7zJzvh56FRKhho2UHmQCiROHlDWomrkgYLQi5fZmNQspq4HuDAbty0mXm8YkC8yWrl2P0Fl9K8QiiKtewQHwCgpB1FwnLrpMBCOik5E3lWpMsTFc11SKBPquB5hUfT0VfJJ2GCMJdCUb6rvH9RPzmeb18fCcAZc05Adj4mxMnZNVSvsITSoi60hw==" Oct 01 22:31:06 volumio go-librespot[11275]: time="2024-10-01T22:31:06+03:00" level=debug msg="completed keyexchange" Oct 01 22:31:06 volumio go-librespot[11275]: time="2024-10-01T22:31:06+03:00" level=debug msg="completed challenge" Oct 01 22:31:06 volumio go-librespot[11275]: time="2024-10-01T22:31:06+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 01 22:31:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 01 22:31:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 01 22:31:06 volumio volumio[898]: info: Connection to go-librespot Websocket closed Oct 01 22:31:08 volumio kernel: hwmon hwmon1: Voltage normalised Oct 01 22:31:09 volumio volumio[898]: info: Getting Spotify volume Oct 01 22:31:09 volumio volumio[898]: (node:898) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 01 22:31:09 volumio volumio[898]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Oct 01 22:31:09 volumio volumio[898]: (node:898) 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: 106) Oct 01 22:31:09 volumio volumio[898]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Oct 01 22:31:09 volumio volumio[898]: info: CoreCommandRouter::volumioGetState Oct 01 22:31:09 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Oct 01 22:31:09 volumio volumio[898]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 01 22:31:10 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 01 22:31:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 748. Oct 01 22:31:10 volumio systemd[1]: Stopped go-librespot Daemon. Oct 01 22:31:10 volumio systemd[1]: Started go-librespot Daemon. Oct 01 22:31:10 volumio go-librespot[11284]: Librespot-go daemon starting... Oct 01 22:31:10 volumio go-librespot[11284]: time="2024-10-01T22:31:10+03:00" level=info msg="generated new device id: 41872fbedd31ec3f5a62af1e91d6076889b0e873" Oct 01 22:31:10 volumio go-librespot[11284]: time="2024-10-01T22:31:10+03:00" level=debug msg="stored credentials found for 322996" Oct 01 22:31:10 volumio go-librespot[11284]: time="2024-10-01T22:31:10+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Oct 01 22:31:10 volumio go-librespot[11284]: time="2024-10-01T22:31:10+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 01 22:31:10 volumio go-librespot[11284]: time="2024-10-01T22:31:10+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 01 22:31:10 volumio go-librespot[11284]: time="2024-10-01T22:31:10+03:00" level=debug msg="zeroconf server listening on port 45985" Oct 01 22:31:10 volumio go-librespot[11284]: time="2024-10-01T22:31:10+03:00" level=debug msg="obtained new client token: AACzek+mydlsOQ6LFqjqp/vDNghbqHsCmV6olZf5hV5J1z+9cWO0UQl1nXbJ4pkqsu5CDSKgL28Gky7kuzGVcVYYWyLWLvQl2gJ/lSBnjGNwR+8eq98V/EhOHzBkgSeZUkEf36heeUwoF1dIVk1MDwyUeUsMxQQ4SDWGWuVie9FMgk8VGqRiGy+0ubA29HjqBqJ8arVG4ve2G8I758n4JJ0YDWIsPsLBsk3OAeEfJg3nk670Cr7bqjP+Og==" Oct 01 22:31:10 volumio go-librespot[11284]: time="2024-10-01T22:31:10+03:00" level=debug msg="completed keyexchange" Oct 01 22:31:10 volumio go-librespot[11284]: time="2024-10-01T22:31:10+03:00" level=debug msg="completed challenge" Oct 01 22:31:10 volumio go-librespot[11284]: time="2024-10-01T22:31:10+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 01 22:31:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 01 22:31:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 01 22:31:12 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Oct 01 22:31:12 volumio volumio[898]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 01 22:31:14 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 01 22:31:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 749. Oct 01 22:31:14 volumio systemd[1]: Stopped go-librespot Daemon. Oct 01 22:31:14 volumio systemd[1]: Started go-librespot Daemon. Oct 01 22:31:14 volumio go-librespot[11295]: Librespot-go daemon starting... Oct 01 22:31:14 volumio go-librespot[11295]: time="2024-10-01T22:31:14+03:00" level=info msg="generated new device id: fb3ef98273f76847d0017e7f381caaef66720b38" Oct 01 22:31:14 volumio go-librespot[11295]: time="2024-10-01T22:31:14+03:00" level=debug msg="stored credentials found for 322996" Oct 01 22:31:14 volumio go-librespot[11295]: time="2024-10-01T22:31:14+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Oct 01 22:31:14 volumio go-librespot[11295]: time="2024-10-01T22:31:14+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 01 22:31:14 volumio go-librespot[11295]: time="2024-10-01T22:31:14+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 01 22:31:14 volumio go-librespot[11295]: time="2024-10-01T22:31:14+03:00" level=debug msg="zeroconf server listening on port 39905" Oct 01 22:31:14 volumio go-librespot[11295]: time="2024-10-01T22:31:14+03:00" level=debug msg="obtained new client token: AACRCJa4EhawV61AAdBFWQg64w86nu6/2kEKxh5ryJNTgl3qoUCF6L+EHTyUjsuZZlTxhuWbL8FIzH7mvFDkZVX0LPsVMBeyBv9d2TAVPHNuALD62KNwAiJzPa3jQP6QePy5spkg3YTlHWdLsfDmsmZ0sV6dZHcJp+8BBhBMbRFnbLMFNj4x/gdkEGxkaDn6uZQtOftiJucyldDKIViI2TO+Fn6AnhU+wNWc7tvxbIWs2j3BamTxMQt7bg==" Oct 01 22:31:14 volumio go-librespot[11295]: time="2024-10-01T22:31:14+03:00" level=debug msg="completed keyexchange" Oct 01 22:31:14 volumio go-librespot[11295]: time="2024-10-01T22:31:14+03:00" level=debug msg="completed challenge" Oct 01 22:31:14 volumio go-librespot[11295]: time="2024-10-01T22:31:14+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 01 22:31:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 01 22:31:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 01 22:31:15 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Oct 01 22:31:15 volumio volumio[898]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 01 22:31:18 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 01 22:31:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 750. Oct 01 22:31:18 volumio systemd[1]: Stopped go-librespot Daemon. Oct 01 22:31:18 volumio systemd[1]: Started go-librespot Daemon. Oct 01 22:31:18 volumio go-librespot[11305]: Librespot-go daemon starting... Oct 01 22:31:18 volumio go-librespot[11305]: time="2024-10-01T22:31:18+03:00" level=info msg="generated new device id: badafd65b49af53ef9ac05f285d94db78f5b6ffe" Oct 01 22:31:18 volumio go-librespot[11305]: time="2024-10-01T22:31:18+03:00" level=debug msg="stored credentials found for 322996" Oct 01 22:31:18 volumio go-librespot[11305]: time="2024-10-01T22:31:18+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 01 22:31:18 volumio go-librespot[11305]: time="2024-10-01T22:31:18+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 01 22:31:18 volumio go-librespot[11305]: time="2024-10-01T22:31:18+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 01 22:31:18 volumio go-librespot[11305]: time="2024-10-01T22:31:18+03:00" level=debug msg="zeroconf server listening on port 44653" Oct 01 22:31:18 volumio go-librespot[11305]: time="2024-10-01T22:31:18+03:00" level=debug msg="obtained new client token: AAALEnTZysN/ye5B5XxvKpMeATUeOiX2dCtwe1dbiEq+jt7BOV5okmoMiJsBrv8qGk41M0h83vhEfjk5oPDse75SIbASYX0vaQCThOREWA/EmoKpPiUVxpE8uARlHuB5UsQVrlNzjtTsJvF6O74cqOxI1CWxtQxRMw0xQMGo8z+TfE+a7OAiD7aCEaunsF5jFFPqGxuRYgvM4/ylClZbAMnXkRpid/rB+d/uTHtlUiSuPLiQpPE61eZe2w==" Oct 01 22:31:18 volumio go-librespot[11305]: time="2024-10-01T22:31:18+03:00" level=debug msg="completed keyexchange" Oct 01 22:31:18 volumio go-librespot[11305]: time="2024-10-01T22:31:18+03:00" level=debug msg="completed challenge" Oct 01 22:31:18 volumio go-librespot[11305]: time="2024-10-01T22:31:18+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 01 22:31:18 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Oct 01 22:31:18 volumio volumio[898]: info: Error connecting to go-librespot Websocket: Error: read ECONNRESET Oct 01 22:31:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 01 22:31:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 01 22:31:21 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Oct 01 22:31:21 volumio volumio[898]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 01 22:31:22 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 01 22:31:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 751. Oct 01 22:31:22 volumio systemd[1]: Stopped go-librespot Daemon. Oct 01 22:31:22 volumio systemd[1]: Started go-librespot Daemon. Oct 01 22:31:22 volumio go-librespot[11315]: Librespot-go daemon starting... Oct 01 22:31:22 volumio go-librespot[11315]: time="2024-10-01T22:31:22+03:00" level=info msg="generated new device id: 49215445e8773dbdcf781e9d64c6e08e45a492be" Oct 01 22:31:22 volumio go-librespot[11315]: time="2024-10-01T22:31:22+03:00" level=debug msg="stored credentials found for 322996" Oct 01 22:31:22 volumio go-librespot[11315]: time="2024-10-01T22:31:22+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Oct 01 22:31:22 volumio go-librespot[11315]: time="2024-10-01T22:31:22+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 01 22:31:22 volumio go-librespot[11315]: time="2024-10-01T22:31:22+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 01 22:31:22 volumio go-librespot[11315]: time="2024-10-01T22:31:22+03:00" level=debug msg="zeroconf server listening on port 37685" Oct 01 22:31:22 volumio go-librespot[11315]: time="2024-10-01T22:31:22+03:00" level=debug msg="obtained new client token: AAA5jEtVU97aoYjl9DzzuslgOVQ47PER3z6mwWIG6gvEmZ7b2owl6LfcvtVwSGPSTDAJ9WlSWANyG/Wkx+wILBbIp7lE5S2CiPy5qFjWuBM+yHFLNhThc5iplGRxc04/fxqnHZZhXOC0tWbdvSt8/6I3ubkKbQbaSlk35eEuC0lpdLF9fHHrBylA7J5T/2CN/SoxvcASReuXV1+/UoS8I1gLuEh+j1WZuAL4UXDT2o3vTMVu22a/H0ZCjQ==" Oct 01 22:31:22 volumio go-librespot[11315]: time="2024-10-01T22:31:22+03:00" level=debug msg="completed keyexchange" Oct 01 22:31:22 volumio go-librespot[11315]: time="2024-10-01T22:31:22+03:00" level=debug msg="completed challenge" Oct 01 22:31:22 volumio go-librespot[11315]: time="2024-10-01T22:31:22+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 01 22:31:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 01 22:31:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 01 22:31:24 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Oct 01 22:31:24 volumio volumio[898]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 01 22:31:26 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 01 22:31:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 752. Oct 01 22:31:26 volumio systemd[1]: Stopped go-librespot Daemon. Oct 01 22:31:26 volumio systemd[1]: Started go-librespot Daemon. Oct 01 22:31:26 volumio go-librespot[11326]: Librespot-go daemon starting... Oct 01 22:31:26 volumio go-librespot[11326]: time="2024-10-01T22:31:26+03:00" level=info msg="generated new device id: 648440fe6667cffeba04db5f335e41972c10570d" Oct 01 22:31:26 volumio go-librespot[11326]: time="2024-10-01T22:31:26+03:00" level=debug msg="stored credentials found for 322996" Oct 01 22:31:26 volumio go-librespot[11326]: time="2024-10-01T22:31:26+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 01 22:31:26 volumio go-librespot[11326]: time="2024-10-01T22:31:26+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 01 22:31:26 volumio go-librespot[11326]: time="2024-10-01T22:31:26+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 01 22:31:26 volumio go-librespot[11326]: time="2024-10-01T22:31:26+03:00" level=debug msg="zeroconf server listening on port 39113" Oct 01 22:31:26 volumio go-librespot[11326]: time="2024-10-01T22:31:26+03:00" level=debug msg="obtained new client token: AABbizYIYUh4/RP/xTa8mC40Cgwc02u4Hbrqads2uWWc0QEft7FzweiaQbJ6HPtFei4PADSZC7iWciPOS5VnHJy6XokLxOtINohfWT+xw00jysPMpmhvltyrvJsVBQHOukNdGITOE2rVPB9P+gQRPpQ6E77zE6jL3SQWqQFozMOu6DfkdOqoiSC6OoW8+WgxSwysew/D+AQhEMvmeXVtNY6D8I3dKXAgv0qiRDRTgFn9OrYMart1RsmeBw==" Oct 01 22:31:26 volumio go-librespot[11326]: time="2024-10-01T22:31:26+03:00" level=debug msg="completed keyexchange" Oct 01 22:31:26 volumio go-librespot[11326]: time="2024-10-01T22:31:26+03:00" level=debug msg="completed challenge" Oct 01 22:31:26 volumio go-librespot[11326]: time="2024-10-01T22:31:26+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 01 22:31:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 01 22:31:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 01 22:31:27 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Oct 01 22:31:28 volumio volumio[898]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 01 22:31:30 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 01 22:31:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 753. Oct 01 22:31:30 volumio systemd[1]: Stopped go-librespot Daemon. Oct 01 22:31:30 volumio systemd[1]: Started go-librespot Daemon. Oct 01 22:31:30 volumio go-librespot[11345]: Librespot-go daemon starting... Oct 01 22:31:30 volumio go-librespot[11345]: time="2024-10-01T22:31:30+03:00" level=info msg="generated new device id: 1204d1d2435e289cdb4a1c9e4736ea9e235c5078" Oct 01 22:31:30 volumio go-librespot[11345]: time="2024-10-01T22:31:30+03:00" level=debug msg="stored credentials found for 322996" Oct 01 22:31:30 volumio go-librespot[11345]: time="2024-10-01T22:31:30+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Oct 01 22:31:30 volumio go-librespot[11345]: time="2024-10-01T22:31:30+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 01 22:31:30 volumio go-librespot[11345]: time="2024-10-01T22:31:30+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 01 22:31:30 volumio go-librespot[11345]: time="2024-10-01T22:31:30+03:00" level=debug msg="zeroconf server listening on port 36211" Oct 01 22:31:30 volumio go-librespot[11345]: time="2024-10-01T22:31:30+03:00" level=debug msg="obtained new client token: AAAqE2etBiiWd34JzH2oNXo1DKA5kCQCjlVTppExDf5+b2nLy+K3KCE/fgS5tb/mCLWXXwASoxziemu7S0grmBXYJdYyb3nAcMy0/juGBNzLY4ZbXh5OJBMrQ3HKLGTR++7WUOT4hTMQR5JzeEgFzBCbE/J9hcRbbfhXMN4ys3faNNBt53ABNBwz92SNpGC0FPtE9pBvfwFaZBMhUe3fYNAlX1SRL8u+uMCfm1qRGyFI96Ej/W45i3BhQA==" Oct 01 22:31:30 volumio go-librespot[11345]: time="2024-10-01T22:31:30+03:00" level=debug msg="completed keyexchange" Oct 01 22:31:30 volumio go-librespot[11345]: time="2024-10-01T22:31:30+03:00" level=debug msg="completed challenge" Oct 01 22:31:30 volumio go-librespot[11345]: time="2024-10-01T22:31:30+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 01 22:31:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 01 22:31:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 01 22:31:31 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Oct 01 22:31:31 volumio volumio[898]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 01 22:31:34 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Oct 01 22:31:34 volumio volumio[898]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 01 22:31:34 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 01 22:31:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 754. Oct 01 22:31:34 volumio systemd[1]: Stopped go-librespot Daemon. Oct 01 22:31:34 volumio systemd[1]: Started go-librespot Daemon. Oct 01 22:31:34 volumio go-librespot[11354]: Librespot-go daemon starting... Oct 01 22:31:34 volumio go-librespot[11354]: time="2024-10-01T22:31:34+03:00" level=info msg="generated new device id: d3674b72dfa8771112be6bec666029a028849c8a" Oct 01 22:31:34 volumio go-librespot[11354]: time="2024-10-01T22:31:34+03:00" level=debug msg="stored credentials found for 322996" Oct 01 22:31:34 volumio volumio[898]: info: Clearing queue after UPNP request Oct 01 22:31:34 volumio go-librespot[11354]: time="2024-10-01T22:31:34+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 01 22:31:34 volumio go-librespot[11354]: time="2024-10-01T22:31:34+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 01 22:31:34 volumio go-librespot[11354]: time="2024-10-01T22:31:34+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 01 22:31:34 volumio go-librespot[11354]: time="2024-10-01T22:31:34+03:00" level=debug msg="zeroconf server listening on port 40077" Oct 01 22:31:34 volumio go-librespot[11354]: time="2024-10-01T22:31:34+03:00" level=debug msg="obtained new client token: AABIoghrZYEeXa2e+RlD3fyvv54n745IEcOFtQpkgwBAbRgfXbrCrL4kAwSEuumyPNYt8mAZuKwIPVfo7TmMXC9+7fvPU5a1ZO5K9zHWKTl7UTR5nBTIOAUn8wAzPo/cNpfmSesVZZVFZLmPlH4PHC4iWqEFxLJvjCJhhIMwFfLzUTwUiMa8Vmrdh2lz/qb/hzXSHH7FxACgOF7wFe5bP+e4Mgzep2eiqbzr0FVo1k1c4foqFptbYjTDOw==" Oct 01 22:31:34 volumio go-librespot[11354]: time="2024-10-01T22:31:34+03:00" level=debug msg="completed keyexchange" Oct 01 22:31:34 volumio volumio[898]: info: CoreStateMachine::ClearQueue Oct 01 22:31:34 volumio volumio[898]: info: CoreStateMachine::stop Oct 01 22:31:34 volumio volumio[898]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 01 22:31:34 volumio volumio[898]: info: CoreStateMachine::stPlaybackTimer Oct 01 22:31:34 volumio volumio[898]: info: CoreStateMachine::updateTrackBlock Oct 01 22:31:34 volumio volumio[898]: info: CorePlayQueue::getTrackBlock Oct 01 22:31:34 volumio volumio[898]: info: CoreStateMachine::pushState Oct 01 22:31:34 volumio volumio[898]: info: CorePlayQueue::getTrack 0 Oct 01 22:31:34 volumio volumio[898]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 01 22:31:34 volumio volumio[898]: info: CoreCommandRouter::volumioPushState Oct 01 22:31:34 volumio volumio[898]: info: MRS: Pushing multiroomSync output update for this device Oct 01 22:31:34 volumio volumio[898]: info: MRS: Pushing multiroomSync output Oct 01 22:31:34 volumio volumio[898]: info: CoreStateMachine::serviceStop Oct 01 22:31:34 volumio volumio[898]: info: CorePlayQueue::getTrack 0 Oct 01 22:31:34 volumio volumio[898]: info: ControllerMpd::stop Oct 01 22:31:34 volumio volumio[898]: verbose: ControllerMpd::sendMpdCommand stop Oct 01 22:31:34 volumio volumio[898]: info: CorePlayQueue::clearPlayQueue Oct 01 22:31:34 volumio volumio[898]: info: CorePlayQueue::saveQueue Oct 01 22:31:34 volumio volumio[898]: info: CoreCommandRouter::volumioPushState Oct 01 22:31:34 volumio volumio[898]: info: MRS: Pushing multiroomSync output update for this device Oct 01 22:31:34 volumio volumio[898]: info: MRS: Pushing multiroomSync output Oct 01 22:31:34 volumio volumio[898]: info: CoreCommandRouter::volumioPushQueue Oct 01 22:31:34 volumio volumio[898]: error: Upnp client error: Error: This socket has been ended by the other party Oct 01 22:31:34 volumio volumio[898]: info: Oct 01 22:31:34 volumio volumio[898]: ---------------------------- MPD announces state update: player Oct 01 22:31:34 volumio volumio[898]: info: sendMpdCommand stop took 50 milliseconds Oct 01 22:31:34 volumio volumio[898]: info: ControllerMpd::getState Oct 01 22:31:34 volumio volumio[898]: verbose: ControllerMpd::sendMpdCommand status Oct 01 22:31:34 volumio volumio[898]: info: sendMpdCommand status took 1 milliseconds Oct 01 22:31:34 volumio volumio[898]: verbose: ControllerMpd::parseState Oct 01 22:31:34 volumio volumio[898]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 01 22:31:34 volumio volumio[898]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 01 22:31:34 volumio volumio[898]: verbose: ControllerMpd::parseTrackInfo Oct 01 22:31:34 volumio volumio[898]: info: ControllerMpd::pushState Oct 01 22:31:34 volumio volumio[898]: info: CoreCommandRouter::servicePushState Oct 01 22:31:34 volumio volumio[898]: info: CoreStateMachine::pushState Oct 01 22:31:34 volumio volumio[898]: info: CorePlayQueue::getTrack 0 Oct 01 22:31:34 volumio volumio[898]: info: CoreCommandRouter::volumioPushState Oct 01 22:31:34 volumio volumio[898]: info: MRS: Pushing multiroomSync output update for this device Oct 01 22:31:34 volumio volumio[898]: info: MRS: Pushing multiroomSync output Oct 01 22:31:34 volumio volumio[898]: info: CorePlayQueue::getTrack 0 Oct 01 22:31:34 volumio volumio[898]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"foobar2000 audio stream","artist":null,"album":null,"uri":"http://192.168.1.128:62435/6/stream.wav","trackType":"wav"} Oct 01 22:31:34 volumio volumio[898]: verbose: CURRENT POSITION 0 Oct 01 22:31:34 volumio volumio[898]: info: CoreStateMachine::syncState stateService stop Oct 01 22:31:34 volumio volumio[898]: info: CoreStateMachine::syncState currentStatus stop Oct 01 22:31:34 volumio volumio[898]: info: CoreStateMachine::pushState Oct 01 22:31:34 volumio volumio[898]: info: CorePlayQueue::getTrack 0 Oct 01 22:31:34 volumio volumio[898]: info: CoreCommandRouter::volumioPushState Oct 01 22:31:34 volumio volumio[898]: info: MRS: Pushing multiroomSync output update for this device Oct 01 22:31:34 volumio volumio[898]: info: MRS: Pushing multiroomSync output Oct 01 22:31:34 volumio volumio[898]: info: No code Oct 01 22:31:34 volumio volumio[898]: info: CoreStateMachine::pushState Oct 01 22:31:34 volumio volumio[898]: info: CorePlayQueue::getTrack 0 Oct 01 22:31:34 volumio volumio[898]: info: CoreCommandRouter::volumioPushState Oct 01 22:31:34 volumio volumio[898]: info: MRS: Pushing multiroomSync output update for this device Oct 01 22:31:34 volumio volumio[898]: info: MRS: Pushing multiroomSync output Oct 01 22:31:34 volumio volumio[898]: info: ------------------------------ 19ms Oct 01 22:31:34 volumio volumio[898]: info: camilladsp spawned new process with pid 11362, instance 1, run: true Oct 01 22:31:34 volumio go-librespot[11354]: time="2024-10-01T22:31:34+03:00" level=debug msg="completed challenge" Oct 01 22:31:34 volumio go-librespot[11354]: time="2024-10-01T22:31:34+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 01 22:31:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 01 22:31:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 01 22:31:36 volumio volumio[1073]: Connection was closed while sending response headers. Oct 01 22:31:37 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Oct 01 22:31:37 volumio volumio[898]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 01 22:31:37 volumio volumio[898]: info: CoreCommandRouter::volumioGetVisibleSources Oct 01 22:31:37 volumio volumio[898]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 01 22:31:37 volumio volumio[898]: info: CoreCommandRouter::volumioGetQueue Oct 01 22:31:37 volumio volumio[898]: info: CoreStateMachine::getQueue Oct 01 22:31:37 volumio volumio[898]: info: CorePlayQueue::getQueue Oct 01 22:31:38 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 01 22:31:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 755. Oct 01 22:31:38 volumio systemd[1]: Stopped go-librespot Daemon. Oct 01 22:31:38 volumio systemd[1]: Started go-librespot Daemon. Oct 01 22:31:38 volumio go-librespot[11370]: Librespot-go daemon starting... Oct 01 22:31:38 volumio go-librespot[11370]: time="2024-10-01T22:31:38+03:00" level=info msg="generated new device id: 24d97c94f12e541b54dd75443356537b13b5e72e" Oct 01 22:31:38 volumio go-librespot[11370]: time="2024-10-01T22:31:38+03:00" level=debug msg="stored credentials found for 322996" Oct 01 22:31:38 volumio go-librespot[11370]: time="2024-10-01T22:31:38+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 01 22:31:38 volumio go-librespot[11370]: time="2024-10-01T22:31:38+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 01 22:31:38 volumio go-librespot[11370]: time="2024-10-01T22:31:38+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 01 22:31:38 volumio go-librespot[11370]: time="2024-10-01T22:31:38+03:00" level=debug msg="zeroconf server listening on port 42705" Oct 01 22:31:38 volumio go-librespot[11370]: time="2024-10-01T22:31:38+03:00" level=debug msg="obtained new client token: AAAyMfqZl/+L9H/i9YybqmGkLx8ZqeCh0VyA0TfX1ng2yVEMAV/WStCFsAfa6k7mPvICUxhhGALx6T2inmprLivKwVjV0qbrs2PpRktvSmnuMFHxegelxT3x5YbSYBiqsA/oKusFMaZ95nqq3iz72SaPlz482POvD1RGQzuFQDQDuMd211Nk6nHNGa45+vu+X8842fra+ybHnukGbD6E9qvN2sp8Rzew9g+w7cTuK7YYP2zy4DVujn047g==" Oct 01 22:31:38 volumio go-librespot[11370]: time="2024-10-01T22:31:38+03:00" level=debug msg="completed keyexchange" Oct 01 22:31:38 volumio go-librespot[11370]: time="2024-10-01T22:31:38+03:00" level=debug msg="completed challenge" Oct 01 22:31:38 volumio go-librespot[11370]: time="2024-10-01T22:31:38+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 01 22:31:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 01 22:31:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 01 22:31:40 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Oct 01 22:31:40 volumio volumio[898]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 01 22:31:40 volumio volumio[898]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 01 22:31:40 volumio volumio[898]: info: Preload queue cleared Oct 01 22:31:41 volumio volumio[898]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 01 22:31:42 volumio volumio[898]: info: Preload queue cleared Oct 01 22:31:42 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 01 22:31:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 756. Oct 01 22:31:42 volumio systemd[1]: Stopped go-librespot Daemon. Oct 01 22:31:42 volumio systemd[1]: Started go-librespot Daemon. Oct 01 22:31:42 volumio go-librespot[11378]: Librespot-go daemon starting... Oct 01 22:31:42 volumio go-librespot[11378]: time="2024-10-01T22:31:42+03:00" level=info msg="generated new device id: bf96afb56fcfb9824aaa7b7bf2ced83f06ff5c48" Oct 01 22:31:42 volumio go-librespot[11378]: time="2024-10-01T22:31:42+03:00" level=debug msg="stored credentials found for 322996" Oct 01 22:31:42 volumio go-librespot[11378]: time="2024-10-01T22:31:42+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 01 22:31:42 volumio go-librespot[11378]: time="2024-10-01T22:31:42+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 01 22:31:42 volumio go-librespot[11378]: time="2024-10-01T22:31:42+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 01 22:31:42 volumio go-librespot[11378]: time="2024-10-01T22:31:42+03:00" level=debug msg="zeroconf server listening on port 34077" Oct 01 22:31:42 volumio go-librespot[11378]: time="2024-10-01T22:31:42+03:00" level=debug msg="obtained new client token: AACAK9/BjMfbgLaThLdB+f/6JvXAfkegs2CPO0lT3ci6Ocwo5StNfDzQXOCnVuhVih0/dHQXAlNFgDMZ0e4pFMRUXTOp6o0jIr41ENtEYn9o0EUahXQDm7qO6oawm7FC/yPdZyg91l1Ig9lkpZ74jaV4OU05VCn537CkFRODq1L3yZaUfAL/71bcfvSqH3lr/a2b/+QzhYGi1UECYVzuaER4KW5i5XhQyMFLaahK5vrL5kD1KJYrmu7Jxw==" Oct 01 22:31:42 volumio go-librespot[11378]: time="2024-10-01T22:31:42+03:00" level=debug msg="completed keyexchange" Oct 01 22:31:42 volumio go-librespot[11378]: time="2024-10-01T22:31:42+03:00" level=debug msg="completed challenge" Oct 01 22:31:43 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Oct 01 22:31:43 volumio go-librespot[11378]: time="2024-10-01T22:31:43+03:00" level=debug msg="new websocket client" Oct 01 22:31:43 volumio volumio[898]: info: Connection to go-librespot Websocket established Oct 01 22:31:43 volumio go-librespot[11378]: time="2024-10-01T22:31:43+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 01 22:31:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 01 22:31:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 01 22:31:43 volumio volumio[898]: info: Connection to go-librespot Websocket closed Oct 01 22:31:43 volumio volumio[898]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 01 22:31:43 volumio kernel: hwmon hwmon1: Undervoltage detected! Oct 01 22:31:44 volumio volumio[898]: info: Preload queue cleared Oct 01 22:31:46 volumio volumio[898]: info: Getting Spotify volume Oct 01 22:31:46 volumio volumio[898]: (node:898) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 01 22:31:46 volumio volumio[898]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Oct 01 22:31:46 volumio volumio[898]: (node:898) 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: 107) Oct 01 22:31:46 volumio volumio[898]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Oct 01 22:31:46 volumio volumio[898]: info: CoreCommandRouter::volumioGetState Oct 01 22:31:46 volumio volumio[898]: info: CorePlayQueue::getTrack 0 Oct 01 22:31:46 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Oct 01 22:31:46 volumio volumio[898]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 01 22:31:46 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 01 22:31:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 757. Oct 01 22:31:46 volumio systemd[1]: Stopped go-librespot Daemon. Oct 01 22:31:46 volumio systemd[1]: Started go-librespot Daemon. Oct 01 22:31:46 volumio go-librespot[11387]: Librespot-go daemon starting... Oct 01 22:31:46 volumio go-librespot[11387]: time="2024-10-01T22:31:46+03:00" level=info msg="generated new device id: a326891bd9b5af6e147f68a391471b522ce38b96" Oct 01 22:31:46 volumio go-librespot[11387]: time="2024-10-01T22:31:46+03:00" level=debug msg="stored credentials found for 322996" Oct 01 22:31:46 volumio go-librespot[11387]: time="2024-10-01T22:31:46+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 01 22:31:46 volumio go-librespot[11387]: time="2024-10-01T22:31:46+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 01 22:31:46 volumio go-librespot[11387]: time="2024-10-01T22:31:46+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 01 22:31:46 volumio go-librespot[11387]: time="2024-10-01T22:31:46+03:00" level=debug msg="zeroconf server listening on port 39001" Oct 01 22:31:46 volumio go-librespot[11387]: time="2024-10-01T22:31:46+03:00" level=debug msg="obtained new client token: AACU8VmavC13tCnb+37utxVNxs5kkSHYy/bRKAPq4Xi1Y2I8UPEJh5WFqxSJg4YKJphv4zb7rCDwzxfv0YMArmr+NDOE/JnYJTdsIug0fAe8Z8j2PBQEl+u5k4fe79FQHGdfuvsz98LivEw3i1hBL+iTsny2DQo3xlUWznyNuwQsEn0v0/4UApvYLVB/0HVsM5fKicno1XsFo+tii9tctl/31eJdo2ZKgusqiVmQDrMyA/sAIKNXiXpiRg==" Oct 01 22:31:46 volumio go-librespot[11387]: time="2024-10-01T22:31:46+03:00" level=debug msg="completed keyexchange" Oct 01 22:31:46 volumio go-librespot[11387]: time="2024-10-01T22:31:46+03:00" level=debug msg="completed challenge" Oct 01 22:31:46 volumio go-librespot[11387]: time="2024-10-01T22:31:46+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 01 22:31:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 01 22:31:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 01 22:31:48 volumio kernel: hwmon hwmon1: Voltage normalised Oct 01 22:31:49 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Oct 01 22:31:49 volumio volumio[898]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 01 22:31:49 volumio volumio[898]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 01 22:31:50 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 01 22:31:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 758. Oct 01 22:31:50 volumio systemd[1]: Stopped go-librespot Daemon. Oct 01 22:31:50 volumio systemd[1]: Started go-librespot Daemon. Oct 01 22:31:50 volumio go-librespot[11396]: Librespot-go daemon starting... Oct 01 22:31:50 volumio go-librespot[11396]: time="2024-10-01T22:31:50+03:00" level=info msg="generated new device id: de3c0fb4005b64d7bf07c05147fd8020a1f55ed5" Oct 01 22:31:50 volumio go-librespot[11396]: time="2024-10-01T22:31:50+03:00" level=debug msg="stored credentials found for 322996" Oct 01 22:31:50 volumio go-librespot[11396]: time="2024-10-01T22:31:50+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Oct 01 22:31:50 volumio go-librespot[11396]: time="2024-10-01T22:31:50+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 01 22:31:50 volumio go-librespot[11396]: time="2024-10-01T22:31:50+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 01 22:31:50 volumio go-librespot[11396]: time="2024-10-01T22:31:50+03:00" level=debug msg="zeroconf server listening on port 39651" Oct 01 22:31:50 volumio go-librespot[11396]: time="2024-10-01T22:31:50+03:00" level=debug msg="obtained new client token: AAAd8eTOxBY/H5UFz4a1krRS+gxMTdirxJASTAsdncl3WiV5WJFObiX5PpWBBu/PoMMpSzHA6TLi/Lor0gtXlscE0/v98wG1qNbtcxJFYpAJTABaC6fcLJfL28wF1Wk3ceUh+mCMGjKXtesMGtKCJEvihdTsL/YzJRxLy67NLl1nvCvggFq6H36yBKoYNUiPtLrPRtWsnqEkrmLsn8ZuPLa7YUCxiaa9l9WK+Mb6sxsBnS5MbeqJfnc+2w==" Oct 01 22:31:50 volumio go-librespot[11396]: time="2024-10-01T22:31:50+03:00" level=debug msg="completed keyexchange" Oct 01 22:31:50 volumio go-librespot[11396]: time="2024-10-01T22:31:50+03:00" level=debug msg="completed challenge" Oct 01 22:31:50 volumio go-librespot[11396]: time="2024-10-01T22:31:50+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 01 22:31:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 01 22:31:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 01 22:31:52 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Oct 01 22:31:52 volumio volumio[898]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 01 22:31:54 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 01 22:31:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 759. Oct 01 22:31:54 volumio systemd[1]: Stopped go-librespot Daemon. Oct 01 22:31:54 volumio systemd[1]: Started go-librespot Daemon. Oct 01 22:31:54 volumio go-librespot[11404]: Librespot-go daemon starting... Oct 01 22:31:54 volumio go-librespot[11404]: time="2024-10-01T22:31:54+03:00" level=info msg="generated new device id: 3765b2587ef900f205402be0f9e1ed5ae6ba9f23" Oct 01 22:31:54 volumio go-librespot[11404]: time="2024-10-01T22:31:54+03:00" level=debug msg="stored credentials found for 322996" Oct 01 22:31:54 volumio go-librespot[11404]: time="2024-10-01T22:31:54+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Oct 01 22:31:54 volumio go-librespot[11404]: time="2024-10-01T22:31:54+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 01 22:31:54 volumio go-librespot[11404]: time="2024-10-01T22:31:54+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 01 22:31:54 volumio go-librespot[11404]: time="2024-10-01T22:31:54+03:00" level=debug msg="zeroconf server listening on port 44273" Oct 01 22:31:54 volumio go-librespot[11404]: time="2024-10-01T22:31:54+03:00" level=debug msg="obtained new client token: AADOx/abvSokc6KZxgIxV5AFxvj8y7TzhwR3U6y3ZPpm6UFn4btp/ARcpwWW7TGAQboU/tP5nMUFFOWPVgy1mMj/0trTXtfNoppPc6tbrSuqmIA9Q8iUeKvT3ugiRpJnYhqQDewFvFKPlWTxBvRtXNBgysIntybsGTbQ3qYK9VKQuWEMlLe+McI2NjOw34xCEnkq2Pr31XNXMHJuQpEC2JOT++Y8QdTiXktLh+oin3k9A0Yqj2PhakgNoQ==" Oct 01 22:31:54 volumio go-librespot[11404]: time="2024-10-01T22:31:54+03:00" level=debug msg="completed keyexchange" Oct 01 22:31:54 volumio go-librespot[11404]: time="2024-10-01T22:31:54+03:00" level=debug msg="completed challenge" Oct 01 22:31:54 volumio go-librespot[11404]: time="2024-10-01T22:31:54+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 01 22:31:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 01 22:31:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 01 22:31:55 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Oct 01 22:31:55 volumio volumio[898]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 01 22:31:56 volumio volumio[898]: info: Preload queue cleared Oct 01 22:31:58 volumio volumio[898]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Godflesh/854a4bc5-5f5f-4be8-a2fe-278d5e143c1d.jpg' Oct 01 22:31:58 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Oct 01 22:31:58 volumio volumio[898]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 01 22:31:58 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 01 22:31:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 760. Oct 01 22:31:58 volumio systemd[1]: Stopped go-librespot Daemon. Oct 01 22:31:58 volumio systemd[1]: Started go-librespot Daemon. Oct 01 22:31:58 volumio go-librespot[11412]: Librespot-go daemon starting... Oct 01 22:31:58 volumio go-librespot[11412]: time="2024-10-01T22:31:58+03:00" level=info msg="generated new device id: 11e4000e05b2151d941b6ced2e2e460ebec966aa" Oct 01 22:31:58 volumio go-librespot[11412]: time="2024-10-01T22:31:58+03:00" level=debug msg="stored credentials found for 322996" Oct 01 22:31:58 volumio go-librespot[11412]: time="2024-10-01T22:31:58+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Oct 01 22:31:58 volumio go-librespot[11412]: time="2024-10-01T22:31:58+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 01 22:31:58 volumio go-librespot[11412]: time="2024-10-01T22:31:58+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 01 22:31:58 volumio go-librespot[11412]: time="2024-10-01T22:31:58+03:00" level=debug msg="zeroconf server listening on port 46145" Oct 01 22:31:58 volumio go-librespot[11412]: time="2024-10-01T22:31:58+03:00" level=debug msg="obtained new client token: AADC2VWluBykR2+7tYQ+u5OgsvZC88YdNYPKeVHiYBxlLOORP1d8cu9deUDJRVYy+Kn9LQBmLcYgsH0yOTwzfATjRVHkOnMcg4XC0Fa8ykgvMQi4ajXSRWnZ82kcUU7ezDwGi5ddyYHcGYBzmPgTt8GUxSb3SdMKC9tRE0/8RyzlRkXyzgX9AbLNagEbEnIAredr/mLNDfQtf5WYDrc88Izb05c6PwzxGR9HTEmoleFa9jXZceaXTi6FGQ==" Oct 01 22:31:58 volumio go-librespot[11412]: time="2024-10-01T22:31:58+03:00" level=debug msg="completed keyexchange" Oct 01 22:31:58 volumio go-librespot[11412]: time="2024-10-01T22:31:58+03:00" level=debug msg="completed challenge" Oct 01 22:31:58 volumio go-librespot[11412]: time="2024-10-01T22:31:58+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 01 22:31:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 01 22:31:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 01 22:32:01 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Oct 01 22:32:01 volumio volumio[898]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 01 22:32:02 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 01 22:32:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 761. Oct 01 22:32:02 volumio systemd[1]: Stopped go-librespot Daemon. Oct 01 22:32:02 volumio systemd[1]: Started go-librespot Daemon. Oct 01 22:32:02 volumio go-librespot[11461]: Librespot-go daemon starting... Oct 01 22:32:02 volumio go-librespot[11461]: time="2024-10-01T22:32:02+03:00" level=info msg="generated new device id: e45fb28718dc26b3db2fc981598e97b5695ccb74" Oct 01 22:32:02 volumio go-librespot[11461]: time="2024-10-01T22:32:02+03:00" level=debug msg="stored credentials found for 322996" Oct 01 22:32:02 volumio go-librespot[11461]: time="2024-10-01T22:32:02+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Oct 01 22:32:02 volumio go-librespot[11461]: time="2024-10-01T22:32:02+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 01 22:32:02 volumio go-librespot[11461]: time="2024-10-01T22:32:02+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 01 22:32:02 volumio go-librespot[11461]: time="2024-10-01T22:32:02+03:00" level=debug msg="zeroconf server listening on port 37651" Oct 01 22:32:02 volumio go-librespot[11461]: time="2024-10-01T22:32:02+03:00" level=debug msg="obtained new client token: AABX4hWMZZC3Z24LefOCdE3kmXyVNhWHonjZqLsaCM+9wuBMDCRkbNdwFZKhZFALUAt3I0gd7uzY+ZLiGZPzP+n7uuW/Gz89Qjzt+2h3wMoTRKnb5ESQbd2qmem77fZKO1YCU0PrfYEgLB1HVCnmqpvpmiJllLkiQOhgudD2fK65tpf5mg/3xHVTnqU6LVAa8xLlsl11l2/iBiwKsIjVhGSAR2INZPCe49DFWpSUVGfp2ssBdLsuNUih/g==" Oct 01 22:32:02 volumio go-librespot[11461]: time="2024-10-01T22:32:02+03:00" level=debug msg="completed keyexchange" Oct 01 22:32:02 volumio go-librespot[11461]: time="2024-10-01T22:32:02+03:00" level=debug msg="completed challenge" Oct 01 22:32:02 volumio go-librespot[11461]: time="2024-10-01T22:32:02+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 01 22:32:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 01 22:32:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 01 22:32:04 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Oct 01 22:32:04 volumio volumio[898]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 01 22:32:05 volumio volumio[898]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 01 22:32:05 volumio volumio[898]: info: Preload queue cleared Oct 01 22:32:06 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 01 22:32:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 762. Oct 01 22:32:06 volumio systemd[1]: Stopped go-librespot Daemon. Oct 01 22:32:06 volumio systemd[1]: Started go-librespot Daemon. Oct 01 22:32:06 volumio go-librespot[11468]: Librespot-go daemon starting... Oct 01 22:32:06 volumio go-librespot[11468]: time="2024-10-01T22:32:06+03:00" level=info msg="generated new device id: d1a7268b95b8d3d0e5d975036e14a44edbb7428f" Oct 01 22:32:06 volumio go-librespot[11468]: time="2024-10-01T22:32:06+03:00" level=debug msg="stored credentials found for 322996" Oct 01 22:32:06 volumio go-librespot[11468]: time="2024-10-01T22:32:06+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 01 22:32:06 volumio go-librespot[11468]: time="2024-10-01T22:32:06+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 01 22:32:06 volumio go-librespot[11468]: time="2024-10-01T22:32:06+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 01 22:32:06 volumio go-librespot[11468]: time="2024-10-01T22:32:06+03:00" level=debug msg="zeroconf server listening on port 39549" Oct 01 22:32:06 volumio go-librespot[11468]: time="2024-10-01T22:32:06+03:00" level=debug msg="obtained new client token: AADEmih05U7P9mHR501YPsK4KX2YVJpbYnzQJxBfK/LvfVPxfijCYR02sh6ca9RBG+A47nkwfHfW2jGMBW9lWZc4XKo39zRHxvGvJjs4nnOhKlfxDioXSzJovmbIt6o9f5tyZbsPVvoW5EpJAjjRkwDVsHBKnnDXSQr2kCbsxMG1PJW0Hb7XZpw8rLey8vanv6E0u4UcL4YmRZGmYDNF4Ns9wJUJtpKI+OdzGb6taBmjlekueNS4m+BNyQ==" Oct 01 22:32:06 volumio go-librespot[11468]: time="2024-10-01T22:32:06+03:00" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed dialing accesspoint: dial tcp 104.199.65.9:4070: connect: connection refused" Oct 01 22:32:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 01 22:32:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 01 22:32:07 volumio volumio[898]: info: Initializing connection to go-librespot Websocket Oct 01 22:32:07 volumio volumio[898]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 01 22:32:07 volumio volumio[898]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 01 22:32:08 volumio volumio[898]: info: Preload queue cleared Oct 01 22:32:08 volumio volumio[898]: info: Preloading song: upnp/http://192.168.1.128:2869/upnphost/udhisapi.dll?control=uuid:47865da3-7200-4b90-897e-b8dbaecf9c73+urn:upnp-org:serviceId:ContentDirectory@14_9e4b7381-11625 Oct 01 22:32:08 volumio volumio[898]: info: Exploding uri upnp/http://192.168.1.128:2869/upnphost/udhisapi.dll?control=uuid:47865da3-7200-4b90-897e-b8dbaecf9c73+urn:upnp-org:serviceId:ContentDirectory@14_9e4b7381-11625 in service upnp_browser Oct 01 22:32:09 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 01 22:32:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 763. Oct 01 22:32:09 volumio systemd[1]: Stopped go-librespot Daemon. Oct 01 22:32:09 volumio systemd[1]: Started go-librespot Daemon. Oct 01 22:32:09 volumio go-librespot[11476]: Librespot-go daemon starting... Oct 01 22:32:09 volumio go-librespot[11476]: time="2024-10-01T22:32:09+03:00" level=info msg="generated new device id: 60723326ab99eeddd5233dde9f6820f6865d4dc7" Oct 01 22:32:09 volumio go-librespot[11476]: time="2024-10-01T22:32:09+03:00" level=debug msg="stored credentials found for 322996" Oct 01 22:32:09 volumio go-librespot[11476]: time="2024-10-01T22:32:09+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Oct 01 22:32:09 volumio go-librespot[11476]: time="2024-10-01T22:32:09+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 01 22:32:09 volumio go-librespot[11476]: time="2024-10-01T22:32:09+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 01 22:32:09 volumio go-librespot[11476]: time="2024-10-01T22:32:09+03:00" level=debug msg="zeroconf server listening on port 42939" Oct 01 22:32:09 volumio go-librespot[11476]: time="2024-10-01T22:32:09+03:00" level=debug msg="obtained new client token: AABiWyFW5I9KKd1c5ZmTUanJkJST7GykSN9wnZi0BpisD7Y6hgzQUo+6PU6SKqZtzLZ1raFMPUXmsS+9wtrEDL1mq9fJuljneFtjIBFcFrf1zN4c0T5OYJELj055vFLxFy0mhecCWrdsSKKZ9WfFNwtSGzSGLzIt3lmxGVFXt+fuuTxYr10l7Yd3u+ntPRftllGNaNp24YFCZirikXqIZ+4MzjrLS4sjSQz2b8Anx8lvAaz0L3Scn9saiw==" Oct 01 22:32:09 volumio volumio[898]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 01 22:32:09 volumio volumio[898]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 01 22:32:09 volumio volumio[898]: TypeError: Cannot read property 'length' of undefined Oct 01 22:32:09 volumio volumio[898]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Oct 01 22:32:09 volumio volumio[898]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Oct 01 22:32:09 volumio volumio[898]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Oct 01 22:32:09 volumio volumio[898]: at Parser.emit (events.js:315:20) Oct 01 22:32:09 volumio volumio[898]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Oct 01 22:32:09 volumio volumio[898]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Oct 01 22:32:09 volumio volumio[898]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Oct 01 22:32:09 volumio volumio[898]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Oct 01 22:32:09 volumio volumio[898]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Oct 01 22:32:09 volumio volumio[898]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Oct 01 22:32:09 volumio volumio[898]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Oct 01 22:32:09 volumio volumio[898]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Oct 01 22:32:09 volumio volumio[898]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Oct 01 22:32:09 volumio volumio[898]: at IncomingMessage.emit (events.js:327:22) Oct 01 22:32:09 volumio volumio[898]: at endReadableNT (internal/streams/readable.js:1327:12) Oct 01 22:32:09 volumio volumio[898]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Oct 01 22:32:09 volumio volumio[898]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 01 22:32:09 volumio go-librespot[11476]: time="2024-10-01T22:32:09+03:00" level=debug msg="completed keyexchange" Oct 01 22:32:10 volumio sudo[11493]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-01 22:31 Oct 01 22:32:10 volumio sudo[11493]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="5fd3886148e72a9cecd88a772d1f6079fb64d11a" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8bb23b009e91ae4c7ecd678f193e7d3b281fca0c" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 22 Jul 2024 07:17:01 PM CEST" VOLUMIO_VERSION="3.742" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="2782e52360f70dfab079c82951ebbbb1"