-- Logs begin at Fri 2024-05-10 11:46:11 CEST, end at Fri 2024-05-10 14:02:43 CEST. -- May 10 14:01:01 volumio volumio[702]: info: Getting Spotify volume May 10 14:01:01 volumio volumio[702]: (node:702) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 May 10 14:01:01 volumio volumio[702]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) May 10 14:01:01 volumio volumio[702]: (node:702) 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: 4600) May 10 14:01:01 volumio volumio[702]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 5 May 10 14:01:01 volumio volumio[702]: info: CoreCommandRouter::volumioGetState May 10 14:01:01 volumio volumio[702]: info: CorePlayQueue::getTrack 0 May 10 14:01:02 volumio volumio[702]: info: Initializing connection to go-librespot Websocket May 10 14:01:02 volumio volumio[702]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 10 14:01:02 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 10 14:01:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14109. May 10 14:01:02 volumio systemd[1]: Stopped go-librespot Daemon. May 10 14:01:02 volumio systemd[1]: Started go-librespot Daemon. May 10 14:01:02 volumio go-librespot[31677]: Librespot-go daemon starting... May 10 14:01:02 volumio go-librespot[31677]: time="2024-05-10T14:01:02+02:00" level=info msg="generated new device id: 4d86cf0f26fd7376409fd05fa4f1d8e451529a89" May 10 14:01:02 volumio go-librespot[31677]: time="2024-05-10T14:01:02+02:00" level=debug msg="stored credentials found for cspxgxr4w2nqbsxykzro5zm83" May 10 14:01:02 volumio go-librespot[31677]: time="2024-05-10T14:01:02+02:00" level=debug msg="obtained new client token: AACzW5X6uNPMB/M74PAvKnBEA5H/56kCaV2Dgso4J0S9WhM+YV5bRmycfzkMeObPq6wem18LW4E0nKyr7f07dmJ5JsPVJMs2WDufdbP1qS3rJr2By3Np5FPCpLoCW+Z4If0tWiQRlDtDPf/1l2AjIUwx7M4wycGcidL5nvMqTby60YZVs1dJRRVSZ6GzXeetJv3cdw8AiEdWCAaZ0ZhbO4SXsFBH1wXsp4bor9JSXZC8ucNE4VKQvf8lNjnqIqKi" May 10 14:01:02 volumio go-librespot[31677]: time="2024-05-10T14:01:02+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" May 10 14:01:02 volumio go-librespot[31677]: time="2024-05-10T14:01:02+02:00" level=debug msg="completed keyexchange" May 10 14:01:03 volumio go-librespot[31677]: time="2024-05-10T14:01:03+02:00" level=debug msg="completed challenge" May 10 14:01:03 volumio go-librespot[31677]: time="2024-05-10T14:01:03+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 10 14:01:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 10 14:01:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 10 14:01:05 volumio volumio[702]: info: Initializing connection to go-librespot Websocket May 10 14:01:05 volumio volumio[702]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 10 14:01:06 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 10 14:01:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14110. May 10 14:01:06 volumio systemd[1]: Stopped go-librespot Daemon. May 10 14:01:06 volumio systemd[1]: Started go-librespot Daemon. May 10 14:01:06 volumio go-librespot[31684]: Librespot-go daemon starting... May 10 14:01:06 volumio go-librespot[31684]: time="2024-05-10T14:01:06+02:00" level=info msg="generated new device id: a7f0ee33f55784fe7adb5a4a18c3dd3b76599808" May 10 14:01:06 volumio go-librespot[31684]: time="2024-05-10T14:01:06+02:00" level=debug msg="stored credentials found for cspxgxr4w2nqbsxykzro5zm83" May 10 14:01:06 volumio go-librespot[31684]: time="2024-05-10T14:01:06+02:00" level=debug msg="obtained new client token: AADP0Z7h8cMoBrOQkrENiP5ZhPkULGsdiD8hKrHtWZo65a/jIzWk3ltBsNq+xsiQVsOgjPy5Fvt8VkEF516cuchZFK809T5n9crJOsNEN5cCUuw9Ymy3SdVJPRU/hPN59njJnnuybayA71Eh8IBoTs2FW9i9q8L5uXVYSOYHYLavrM4YCwRmYrT1jqTiRPLkEHplliUj86BgglQ4TaBJKnbZA5ZlW/ScgMtx8TRRvn/ttOHH+vLcblEkpKUpZCHz" May 10 14:01:07 volumio go-librespot[31684]: time="2024-05-10T14:01:07+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" May 10 14:01:07 volumio go-librespot[31684]: time="2024-05-10T14:01:07+02:00" level=debug msg="completed keyexchange" May 10 14:01:07 volumio go-librespot[31684]: time="2024-05-10T14:01:07+02:00" level=debug msg="completed challenge" May 10 14:01:07 volumio go-librespot[31684]: time="2024-05-10T14:01:07+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 10 14:01:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 10 14:01:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 10 14:01:08 volumio volumio[702]: info: Initializing connection to go-librespot Websocket May 10 14:01:08 volumio volumio[702]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 10 14:01:10 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 10 14:01:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14111. May 10 14:01:10 volumio systemd[1]: Stopped go-librespot Daemon. May 10 14:01:10 volumio systemd[1]: Started go-librespot Daemon. May 10 14:01:10 volumio go-librespot[31691]: Librespot-go daemon starting... May 10 14:01:11 volumio go-librespot[31691]: time="2024-05-10T14:01:11+02:00" level=info msg="generated new device id: 7170899aa1954ec7ed6712680aa1f0363f8feec3" May 10 14:01:11 volumio go-librespot[31691]: time="2024-05-10T14:01:11+02:00" level=debug msg="stored credentials found for cspxgxr4w2nqbsxykzro5zm83" May 10 14:01:11 volumio volumio[702]: info: Initializing connection to go-librespot Websocket May 10 14:01:11 volumio go-librespot[31691]: time="2024-05-10T14:01:11+02:00" level=debug msg="new websocket client" May 10 14:01:11 volumio volumio[702]: info: Connection to go-librespot Websocket established May 10 14:01:11 volumio go-librespot[31691]: time="2024-05-10T14:01:11+02:00" level=debug msg="obtained new client token: AABv+AxDVzBsk6ZyLSnPlh8+jvwLdEBWnLDRUYce3a1o4Meh48QWA0Oy7frl/IxapQsUG8ftgHMgerz5mKgQ02qKS8WvYrjSuc4HnCichRuxIO1be5EVs16n4/Epn3SpnKl6YglnI9r/l2dKLE7J8eIYRg4jlRLtqFRUJC7QdCYfr6L4KqwAIaNhIDFr/BKT/VwN5rHF7RqXsPP5VOjfjA6WEX4PRn/pfmIi2xLXqJg/1otqN7zIy4JjfjkTF44m" May 10 14:01:11 volumio go-librespot[31691]: time="2024-05-10T14:01:11+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" May 10 14:01:11 volumio go-librespot[31691]: time="2024-05-10T14:01:11+02:00" level=debug msg="completed keyexchange" May 10 14:01:12 volumio go-librespot[31691]: time="2024-05-10T14:01:12+02:00" level=debug msg="completed challenge" May 10 14:01:12 volumio go-librespot[31691]: time="2024-05-10T14:01:12+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 10 14:01:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 10 14:01:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 10 14:01:12 volumio volumio[702]: info: Connection to go-librespot Websocket closed May 10 14:01:14 volumio volumio[702]: info: Getting Spotify volume May 10 14:01:14 volumio volumio[702]: (node:702) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 May 10 14:01:14 volumio volumio[702]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) May 10 14:01:14 volumio volumio[702]: (node:702) 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: 4601) May 10 14:01:14 volumio volumio[702]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 5 May 10 14:01:14 volumio volumio[702]: info: CoreCommandRouter::volumioGetState May 10 14:01:14 volumio volumio[702]: info: CorePlayQueue::getTrack 0 May 10 14:01:15 volumio volumio[702]: info: Initializing connection to go-librespot Websocket May 10 14:01:15 volumio volumio[702]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 10 14:01:15 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 10 14:01:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14112. May 10 14:01:15 volumio systemd[1]: Stopped go-librespot Daemon. May 10 14:01:15 volumio systemd[1]: Started go-librespot Daemon. May 10 14:01:15 volumio go-librespot[31699]: Librespot-go daemon starting... May 10 14:01:15 volumio go-librespot[31699]: time="2024-05-10T14:01:15+02:00" level=info msg="generated new device id: d3dd526bd5ad608880ebdddca98fa7a627152e56" May 10 14:01:15 volumio go-librespot[31699]: time="2024-05-10T14:01:15+02:00" level=debug msg="stored credentials found for cspxgxr4w2nqbsxykzro5zm83" May 10 14:01:15 volumio go-librespot[31699]: time="2024-05-10T14:01:15+02:00" level=debug msg="obtained new client token: AACguPlcc+AR7WAZfn2E8A3TL+OpjyzQ+cOQ9GUs0nyGRGlW4FFA6BmiZ6xzBQ+GkjkNiRjDNfVDD8rP80mAHYWnAo4S0q1xwrR9GDrG8rfrK88GXx9e6g1Ghu5aG0ePe/MDRZUO2Z93tp1d+TGYPaAcx0pCKXyK7RqhUspae4o6YudiDcTMsNvRmtk0PKdsHoFUB4H8EvnPRJFTT8byRBaJt9+TJbzaSlHRzrN1J86IzPV9xJLLI/CLxkYNgz/L" May 10 14:01:15 volumio go-librespot[31699]: time="2024-05-10T14:01:15+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" May 10 14:01:15 volumio go-librespot[31699]: time="2024-05-10T14:01:15+02:00" level=debug msg="completed keyexchange" May 10 14:01:16 volumio go-librespot[31699]: time="2024-05-10T14:01:16+02:00" level=debug msg="completed challenge" May 10 14:01:16 volumio go-librespot[31699]: time="2024-05-10T14:01:16+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 10 14:01:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 10 14:01:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 10 14:01:18 volumio volumio[702]: info: Initializing connection to go-librespot Websocket May 10 14:01:18 volumio volumio[702]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 10 14:01:19 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 10 14:01:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14113. May 10 14:01:19 volumio systemd[1]: Stopped go-librespot Daemon. May 10 14:01:19 volumio systemd[1]: Started go-librespot Daemon. May 10 14:01:19 volumio go-librespot[31707]: Librespot-go daemon starting... May 10 14:01:19 volumio go-librespot[31707]: time="2024-05-10T14:01:19+02:00" level=info msg="generated new device id: 3cf1dd65ac4981330a73090a12a6bf358680f6f5" May 10 14:01:19 volumio go-librespot[31707]: time="2024-05-10T14:01:19+02:00" level=debug msg="stored credentials found for cspxgxr4w2nqbsxykzro5zm83" May 10 14:01:19 volumio go-librespot[31707]: time="2024-05-10T14:01:19+02:00" level=debug msg="obtained new client token: AAA+0UyDPT6BJbu4+eT9WxUQiHnycxCP8zsSk0uLQU5T5Nq+CcdQveclw4iHpTRtoSV7gFbjT4TOGfDLpZY1pFrOw3/Jgthb88CdAgkHDZK2ou1HBT9sg1/RV+8vA/LbLaq8fovuSQ2rgxEmki0T0mQDJUl8Ki5H27XD5okb9AtY8IWgI0VIyM1RikuoBtbBhgadSLulrM31no3ZsKmpTvGW/mvQwt6zwlf3N0DNywz1jZd+jaVYy9xYbDrHEX31" May 10 14:01:20 volumio go-librespot[31707]: time="2024-05-10T14:01:20+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" May 10 14:01:20 volumio go-librespot[31707]: time="2024-05-10T14:01:20+02:00" level=debug msg="completed keyexchange" May 10 14:01:20 volumio go-librespot[31707]: time="2024-05-10T14:01:20+02:00" level=debug msg="completed challenge" May 10 14:01:20 volumio go-librespot[31707]: time="2024-05-10T14:01:20+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 10 14:01:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 10 14:01:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 10 14:01:21 volumio volumio[702]: info: Initializing connection to go-librespot Websocket May 10 14:01:21 volumio volumio[702]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 10 14:01:23 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 10 14:01:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14114. May 10 14:01:23 volumio systemd[1]: Stopped go-librespot Daemon. May 10 14:01:24 volumio systemd[1]: Started go-librespot Daemon. May 10 14:01:24 volumio go-librespot[31715]: Librespot-go daemon starting... May 10 14:01:24 volumio go-librespot[31715]: time="2024-05-10T14:01:24+02:00" level=info msg="generated new device id: 530835d6ee4a0dd950d2b36d91d4e39253eb3eac" May 10 14:01:24 volumio go-librespot[31715]: time="2024-05-10T14:01:24+02:00" level=debug msg="stored credentials found for cspxgxr4w2nqbsxykzro5zm83" May 10 14:01:24 volumio go-librespot[31715]: time="2024-05-10T14:01:24+02:00" level=debug msg="obtained new client token: AAAYfxdLaL7tVhyAXBugss1WXKaSK05gttyZrhXLU8f52VQyC3t9FOcFJZffJ6xZ2DYn5P4+ocawacEMeD4Z74plHtm+b/LgDgnMFAJmElMZvvJdoBLRajmR0E09hYnq6+t5IChXykvu0h3Fbk8jUhIDMxG4BRrbcPlwutqjciW+FcjTwtTC/vE4EtzOs3WNl6318ZiYwzVxE9zAHQLMyXZo15xdw7t2TjmCXJLDkyFcsNF+veog4R3HgomwDA==" May 10 14:01:24 volumio volumio[702]: info: Initializing connection to go-librespot Websocket May 10 14:01:24 volumio go-librespot[31715]: time="2024-05-10T14:01:24+02:00" level=debug msg="new websocket client" May 10 14:01:24 volumio volumio[702]: info: Connection to go-librespot Websocket established May 10 14:01:24 volumio go-librespot[31715]: time="2024-05-10T14:01:24+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" May 10 14:01:24 volumio go-librespot[31715]: time="2024-05-10T14:01:24+02:00" level=debug msg="completed keyexchange" May 10 14:01:25 volumio go-librespot[31715]: time="2024-05-10T14:01:25+02:00" level=debug msg="completed challenge" May 10 14:01:25 volumio go-librespot[31715]: time="2024-05-10T14:01:25+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 10 14:01:25 volumio volumio[702]: info: Connection to go-librespot Websocket closed May 10 14:01:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 10 14:01:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 10 14:01:27 volumio volumio[702]: info: Getting Spotify volume May 10 14:01:27 volumio volumio[702]: (node:702) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 May 10 14:01:27 volumio volumio[702]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) May 10 14:01:27 volumio volumio[702]: (node:702) 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: 4602) May 10 14:01:27 volumio volumio[702]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 5 May 10 14:01:27 volumio volumio[702]: info: CoreCommandRouter::volumioGetState May 10 14:01:27 volumio volumio[702]: info: CorePlayQueue::getTrack 0 May 10 14:01:28 volumio volumio[702]: info: Initializing connection to go-librespot Websocket May 10 14:01:28 volumio volumio[702]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 10 14:01:28 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 10 14:01:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14115. May 10 14:01:28 volumio systemd[1]: Stopped go-librespot Daemon. May 10 14:01:28 volumio systemd[1]: Started go-librespot Daemon. May 10 14:01:28 volumio go-librespot[31723]: Librespot-go daemon starting... May 10 14:01:28 volumio go-librespot[31723]: time="2024-05-10T14:01:28+02:00" level=info msg="generated new device id: 7fe43c215bd3ac3409a4576ef9be635e030ce267" May 10 14:01:28 volumio go-librespot[31723]: time="2024-05-10T14:01:28+02:00" level=debug msg="stored credentials found for cspxgxr4w2nqbsxykzro5zm83" May 10 14:01:28 volumio go-librespot[31723]: time="2024-05-10T14:01:28+02:00" level=debug msg="obtained new client token: AAAWAoK+YCositEiQd2dnphKYLSqOtvnN1MAKEPe+ZLULZStepLea55DRzrOsQJU8P/39lNeJ0x4W9H+FPt/ATsA5SuYy2lr1hJLDjJk1kPBQRO4Gu0jMJy7QXFJN0idP565GSTlQDLH3rAkflj4USn2Ehe7MSmNfXE9qFAKbAR5jy3CTDLdMi3hey9YZB5D7eZJJ5DBV0ZVvRCPEwAiCI4I6VcEF9X1A1Vbrfz2F3HL+LFB1oCYGNjLjfI6KOKq" May 10 14:01:28 volumio go-librespot[31723]: time="2024-05-10T14:01:28+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" May 10 14:01:28 volumio go-librespot[31723]: time="2024-05-10T14:01:28+02:00" level=debug msg="completed keyexchange" May 10 14:01:29 volumio go-librespot[31723]: time="2024-05-10T14:01:29+02:00" level=debug msg="completed challenge" May 10 14:01:29 volumio go-librespot[31723]: time="2024-05-10T14:01:29+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 10 14:01:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 10 14:01:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 10 14:01:31 volumio volumio[702]: info: Initializing connection to go-librespot Websocket May 10 14:01:31 volumio volumio[702]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 10 14:01:32 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 10 14:01:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14116. May 10 14:01:32 volumio systemd[1]: Stopped go-librespot Daemon. May 10 14:01:32 volumio systemd[1]: Started go-librespot Daemon. May 10 14:01:32 volumio go-librespot[31768]: Librespot-go daemon starting... May 10 14:01:32 volumio go-librespot[31768]: time="2024-05-10T14:01:32+02:00" level=info msg="generated new device id: 5f160467b150ca106cd14cfdd0e4b94b7e5eccc2" May 10 14:01:32 volumio go-librespot[31768]: time="2024-05-10T14:01:32+02:00" level=debug msg="stored credentials found for cspxgxr4w2nqbsxykzro5zm83" May 10 14:01:32 volumio go-librespot[31768]: time="2024-05-10T14:01:32+02:00" level=debug msg="obtained new client token: AAA58yDLXQvDQpmk+cgEJ7S4Ryx0JZpGu0zNKvvQ7aF0pL6ElVv7cSiQaqxBLOs0h+AtqUTp12mM1sazup4ryPKCV6YPb/OMvXhtUOeXpW60BEdvJKSljbUqL9NqDAoSZwKvTwy4zCu4J8aRR3vT47ZpZOG4b+DcFA0gp1QGu42CqFoqwVH8sjEVRwv2eCdnwYzijqD3+CpwfrvgD0O6S3Bp5NlsqTQ8TnUJSVYTTX+FvB10nOimM/OZOWtXD2Yb" May 10 14:01:32 volumio go-librespot[31768]: time="2024-05-10T14:01:32+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" May 10 14:01:33 volumio go-librespot[31768]: time="2024-05-10T14:01:33+02:00" level=debug msg="completed keyexchange" May 10 14:01:33 volumio go-librespot[31768]: time="2024-05-10T14:01:33+02:00" level=debug msg="completed challenge" May 10 14:01:33 volumio go-librespot[31768]: time="2024-05-10T14:01:33+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 10 14:01:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 10 14:01:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 10 14:01:34 volumio volumio[702]: info: Initializing connection to go-librespot Websocket May 10 14:01:34 volumio volumio[702]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 10 14:01:36 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 10 14:01:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14117. May 10 14:01:36 volumio systemd[1]: Stopped go-librespot Daemon. May 10 14:01:36 volumio systemd[1]: Started go-librespot Daemon. May 10 14:01:36 volumio go-librespot[31776]: Librespot-go daemon starting... May 10 14:01:36 volumio go-librespot[31776]: time="2024-05-10T14:01:36+02:00" level=info msg="generated new device id: 34e58295d4a2ebcd74853b78d538febd7a95a7cf" May 10 14:01:36 volumio go-librespot[31776]: time="2024-05-10T14:01:36+02:00" level=debug msg="stored credentials found for cspxgxr4w2nqbsxykzro5zm83" May 10 14:01:36 volumio go-librespot[31776]: time="2024-05-10T14:01:36+02:00" level=debug msg="obtained new client token: AACVVg5v8VOUryYQWwIuyeBiksrI+l1+M4U5myx0fremtp0YGJ7IANPdk1DcDz6n6U40jcK9fIII8Kq3WDwLZkuwd33A3l1cGj0X8jnmcxQNbPPqbeQ72cOl78e/ktRjZlSN+RzfHxWSF8ONP29nKLJGQ4WbRicmJVUilJ2yKrvfujLibIU520S5JCHNhouiT2cPdWwiTbQcK4P8wukHVQXrphwnH7YPny9x352y5A5EHpLJ/Ina2qQJF5P6Q2Gf" May 10 14:01:37 volumio volumio[702]: info: Initializing connection to go-librespot Websocket May 10 14:01:37 volumio go-librespot[31776]: time="2024-05-10T14:01:37+02:00" level=debug msg="new websocket client" May 10 14:01:37 volumio volumio[702]: info: Connection to go-librespot Websocket established May 10 14:01:37 volumio go-librespot[31776]: time="2024-05-10T14:01:37+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" May 10 14:01:37 volumio go-librespot[31776]: time="2024-05-10T14:01:37+02:00" level=debug msg="completed keyexchange" May 10 14:01:37 volumio go-librespot[31776]: time="2024-05-10T14:01:37+02:00" level=debug msg="completed challenge" May 10 14:01:37 volumio go-librespot[31776]: time="2024-05-10T14:01:37+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 10 14:01:37 volumio volumio[702]: info: Connection to go-librespot Websocket closed May 10 14:01:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 10 14:01:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 10 14:01:40 volumio volumio[702]: info: Getting Spotify volume May 10 14:01:40 volumio volumio[702]: (node:702) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 May 10 14:01:40 volumio volumio[702]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) May 10 14:01:40 volumio volumio[702]: (node:702) 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: 4603) May 10 14:01:40 volumio volumio[702]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 5 May 10 14:01:40 volumio volumio[702]: info: CoreCommandRouter::volumioGetState May 10 14:01:40 volumio volumio[702]: info: CorePlayQueue::getTrack 0 May 10 14:01:40 volumio volumio[702]: info: Initializing connection to go-librespot Websocket May 10 14:01:40 volumio volumio[702]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 10 14:01:40 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 10 14:01:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14118. May 10 14:01:40 volumio systemd[1]: Stopped go-librespot Daemon. May 10 14:01:40 volumio systemd[1]: Started go-librespot Daemon. May 10 14:01:40 volumio go-librespot[31784]: Librespot-go daemon starting... May 10 14:01:40 volumio go-librespot[31784]: time="2024-05-10T14:01:40+02:00" level=info msg="generated new device id: 05176c6f3123bafe9558862a8ba2029e7ff3f5c5" May 10 14:01:40 volumio go-librespot[31784]: time="2024-05-10T14:01:40+02:00" level=debug msg="stored credentials found for cspxgxr4w2nqbsxykzro5zm83" May 10 14:01:41 volumio go-librespot[31784]: time="2024-05-10T14:01:41+02:00" level=debug msg="obtained new client token: AADPys/VJIqd7fbQUQV2tMts2i9EziuSVeBNobr20E/DEXxKmblVCWP9NNz7T16XOC+71ACwYBmWHtGZ5oJvvOnTpUaWNZTZdsgzH58zHQJnJA3GTj1aI02iHxqz6ZIz6XTz/y4euA4t1zXgiB4b2FHDz/JO7wxBMXSh0YFQr0QGQGQE4HJb62FAi2YfX9NVj3b9Iva4LTHy+3bpTxYNvx237RV4KIfAa161mxQPgW/3YeGDqcjciBMt7a0MzA==" May 10 14:01:41 volumio go-librespot[31784]: time="2024-05-10T14:01:41+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" May 10 14:01:41 volumio go-librespot[31784]: time="2024-05-10T14:01:41+02:00" level=debug msg="completed keyexchange" May 10 14:01:41 volumio go-librespot[31784]: time="2024-05-10T14:01:41+02:00" level=debug msg="completed challenge" May 10 14:01:42 volumio go-librespot[31784]: time="2024-05-10T14:01:42+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 10 14:01:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 10 14:01:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 10 14:01:43 volumio volumio[702]: info: Initializing connection to go-librespot Websocket May 10 14:01:43 volumio volumio[702]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 10 14:01:45 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 10 14:01:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14119. May 10 14:01:45 volumio systemd[1]: Stopped go-librespot Daemon. May 10 14:01:45 volumio systemd[1]: Started go-librespot Daemon. May 10 14:01:45 volumio go-librespot[31792]: Librespot-go daemon starting... May 10 14:01:45 volumio go-librespot[31792]: time="2024-05-10T14:01:45+02:00" level=info msg="generated new device id: 7c278ce5d314b7649aad473562e557adb1a0c7e2" May 10 14:01:45 volumio go-librespot[31792]: time="2024-05-10T14:01:45+02:00" level=debug msg="stored credentials found for cspxgxr4w2nqbsxykzro5zm83" May 10 14:01:45 volumio go-librespot[31792]: time="2024-05-10T14:01:45+02:00" level=debug msg="obtained new client token: AABJ2GDUMxgx0BaBi/8Kpv6w+F+jRoszUd9IuTuspKklxhyF8fEO/LAEtTRz3Fp6IjImEZpP9oRchpy+5wwKJMKeGFsrW47B4h/LwcM1E1t4/ejD2mHm/d08mCA6L48vUFd50eQtg/Dpr3cJKflm2BHBbtWnuaGxC0sIU2ejz+A+7DrtcNrCrXmuEfkVZ8L7sRYPw7F4nqVPM1Hi8lHsMuDsL4RTi6E9KxbDIFyPTU2RdrpazDq1mbBKtGz46Rif" May 10 14:01:45 volumio go-librespot[31792]: time="2024-05-10T14:01:45+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" May 10 14:01:45 volumio go-librespot[31792]: time="2024-05-10T14:01:45+02:00" level=debug msg="completed keyexchange" May 10 14:01:46 volumio go-librespot[31792]: time="2024-05-10T14:01:46+02:00" level=debug msg="completed challenge" May 10 14:01:46 volumio go-librespot[31792]: time="2024-05-10T14:01:46+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 10 14:01:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 10 14:01:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 10 14:01:46 volumio volumio[702]: info: Initializing connection to go-librespot Websocket May 10 14:01:46 volumio volumio[702]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 10 14:01:49 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 10 14:01:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14120. May 10 14:01:49 volumio systemd[1]: Stopped go-librespot Daemon. May 10 14:01:49 volumio systemd[1]: Started go-librespot Daemon. May 10 14:01:49 volumio go-librespot[31799]: Librespot-go daemon starting... May 10 14:01:49 volumio go-librespot[31799]: time="2024-05-10T14:01:49+02:00" level=info msg="generated new device id: be9e3bdf73646aa9ba7eb6ecc600c927e6cb4c56" May 10 14:01:49 volumio go-librespot[31799]: time="2024-05-10T14:01:49+02:00" level=debug msg="stored credentials found for cspxgxr4w2nqbsxykzro5zm83" May 10 14:01:49 volumio go-librespot[31799]: time="2024-05-10T14:01:49+02:00" level=debug msg="obtained new client token: AABArHoZZ1bv1kUAAbKYAQW1KR/gOd6Nbpni1l+XDo2A0x1ytm9CqLy2pSF8WeyGArq4RD4l58I7E9cqSGNinVmsAW9pvbGLLXqPQOKeuuozXofIPB9Bj6bbcJLwG2dWjc57hGzf4d9l0dOTjA9kWBbC+CfcDDNQwlus6dXr0zAtWx0MQFJa9WvBWMHCmWzUyBq5TH6A4/7RBglk9NjELbxX4h4k1amHUlRmTCh53wKxCNIMx1SNwgeqKOKEjE4j" May 10 14:01:49 volumio volumio[702]: info: Initializing connection to go-librespot Websocket May 10 14:01:49 volumio volumio[702]: info: Connection to go-librespot Websocket established May 10 14:01:49 volumio go-librespot[31799]: time="2024-05-10T14:01:49+02:00" level=debug msg="new websocket client" May 10 14:01:49 volumio go-librespot[31799]: time="2024-05-10T14:01:49+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" May 10 14:01:49 volumio go-librespot[31799]: time="2024-05-10T14:01:49+02:00" level=debug msg="completed keyexchange" May 10 14:01:50 volumio go-librespot[31799]: time="2024-05-10T14:01:50+02:00" level=debug msg="completed challenge" May 10 14:01:50 volumio go-librespot[31799]: time="2024-05-10T14:01:50+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 10 14:01:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 10 14:01:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 10 14:01:50 volumio volumio[702]: info: Connection to go-librespot Websocket closed May 10 14:01:52 volumio volumio[702]: info: Getting Spotify volume May 10 14:01:52 volumio volumio[702]: (node:702) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 May 10 14:01:52 volumio volumio[702]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) May 10 14:01:52 volumio volumio[702]: (node:702) 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: 4604) May 10 14:01:52 volumio volumio[702]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 5 May 10 14:01:52 volumio volumio[702]: info: CoreCommandRouter::volumioGetState May 10 14:01:52 volumio volumio[702]: info: CorePlayQueue::getTrack 0 May 10 14:01:53 volumio volumio[702]: info: Initializing connection to go-librespot Websocket May 10 14:01:53 volumio volumio[702]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 10 14:01:53 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 10 14:01:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14121. May 10 14:01:53 volumio systemd[1]: Stopped go-librespot Daemon. May 10 14:01:53 volumio systemd[1]: Started go-librespot Daemon. May 10 14:01:53 volumio go-librespot[31806]: Librespot-go daemon starting... May 10 14:01:53 volumio go-librespot[31806]: time="2024-05-10T14:01:53+02:00" level=info msg="generated new device id: fe07ec8ca290325c2fb4498121ac82ba60e6628e" May 10 14:01:53 volumio go-librespot[31806]: time="2024-05-10T14:01:53+02:00" level=debug msg="stored credentials found for cspxgxr4w2nqbsxykzro5zm83" May 10 14:01:53 volumio go-librespot[31806]: time="2024-05-10T14:01:53+02:00" level=debug msg="obtained new client token: AAA4T5rFPXTXdKTnvo6Ig6p3xmI6u4r0FigVvS4bEaw6F2/hVn2ux7Bj+hmk6ADBOW6Yf8yYRLPXSHU/5Dnt+WUmuUPj51DhYafo/vUvBSI+0lC9SzzOorhJ7s3+gGoM1tBMWfGM15jG6bHSANp9dHhycSnkPex3khOCgtwC/uop7NEb75slZxNl74X7NnFv+b5gjbN+CjkDU49hkdVKlD+M+EvH+zr0fHNS9pMlVObb11RYFytnX5EFVG/ugI+h" May 10 14:01:54 volumio go-librespot[31806]: time="2024-05-10T14:01:54+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" May 10 14:01:54 volumio go-librespot[31806]: time="2024-05-10T14:01:54+02:00" level=debug msg="completed keyexchange" May 10 14:01:54 volumio go-librespot[31806]: time="2024-05-10T14:01:54+02:00" level=debug msg="completed challenge" May 10 14:01:54 volumio go-librespot[31806]: time="2024-05-10T14:01:54+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 10 14:01:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 10 14:01:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 10 14:01:56 volumio volumio[702]: info: Initializing connection to go-librespot Websocket May 10 14:01:56 volumio volumio[702]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 10 14:01:57 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 10 14:01:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14122. May 10 14:01:57 volumio systemd[1]: Stopped go-librespot Daemon. May 10 14:01:57 volumio systemd[1]: Started go-librespot Daemon. May 10 14:01:57 volumio go-librespot[31814]: Librespot-go daemon starting... May 10 14:01:58 volumio go-librespot[31814]: time="2024-05-10T14:01:58+02:00" level=info msg="generated new device id: 21aefa383d510bed19e1388c81c949e9e4cbb1f3" May 10 14:01:58 volumio go-librespot[31814]: time="2024-05-10T14:01:58+02:00" level=debug msg="stored credentials found for cspxgxr4w2nqbsxykzro5zm83" May 10 14:01:58 volumio go-librespot[31814]: time="2024-05-10T14:01:58+02:00" level=debug msg="obtained new client token: AADo0WAuegAztjt05WemISpNFXXYiPF+dPyGAZ/ZiG8x6SW9JKBqoNsRzWC6zCC/Ad0OazWU/mAwbMpQXhFjHImTvc6E6EtbfcECGIrPFAs/dj4iZSel8Mh66t094y/TiGNjOu+B3s7SfJ+FE86CCkSoLu21IMWcS6JzZyEmqwCvz3/pVGfV+IIMyhRLRGsQeCC0A//ct3TsaYN7QzAsjqITStjX5/k61x9bxi/y2m6ulfQTZeQYLM79LsZCBA==" May 10 14:01:58 volumio go-librespot[31814]: time="2024-05-10T14:01:58+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" May 10 14:01:58 volumio go-librespot[31814]: time="2024-05-10T14:01:58+02:00" level=debug msg="completed keyexchange" May 10 14:01:58 volumio go-librespot[31814]: time="2024-05-10T14:01:58+02:00" level=debug msg="completed challenge" May 10 14:01:59 volumio go-librespot[31814]: time="2024-05-10T14:01:59+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 10 14:01:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 10 14:01:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 10 14:01:59 volumio volumio[702]: info: Initializing connection to go-librespot Websocket May 10 14:01:59 volumio volumio[702]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 10 14:02:01 volumio volumio[702]: verbose: New Socket.io Connection to 192.168.50.10 from 192.168.50.68 UA: okhttp/4.9.2 Total Clients: 5 May 10 14:02:01 volumio volumio[702]: info: CoreCommandRouter::volumioGetState May 10 14:02:01 volumio volumio[702]: info: CorePlayQueue::getTrack 0 May 10 14:02:01 volumio volumio[702]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 10 14:02:01 volumio volumio[702]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 10 14:02:02 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 10 14:02:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14123. May 10 14:02:02 volumio systemd[1]: Stopped go-librespot Daemon. May 10 14:02:02 volumio systemd[1]: Started go-librespot Daemon. May 10 14:02:02 volumio go-librespot[31823]: Librespot-go daemon starting... May 10 14:02:02 volumio go-librespot[31823]: time="2024-05-10T14:02:02+02:00" level=info msg="generated new device id: 84708895f02316a39bd92550345dbc67af6b0bc5" May 10 14:02:02 volumio go-librespot[31823]: time="2024-05-10T14:02:02+02:00" level=debug msg="stored credentials found for cspxgxr4w2nqbsxykzro5zm83" May 10 14:02:02 volumio go-librespot[31823]: time="2024-05-10T14:02:02+02:00" level=debug msg="obtained new client token: AAAZQFO1YdE15KQkhvQW2fPGctLMIc5ZLoxSwj0rRE/yZpmHbsBiWmbdtGwm35+FJs5v5653keu3f6dDJzD97Y9+PVuIFea1FxuirUPzdAcHNZNUDTkEus+dEaDUpvDVLnZ6rKtId/Pas3XQaWQQuvyt/cTRQ8Ht+IMS5Z9HOEQ0Yzhn9PUGyro5vnzgk/tuVqwgznYUkGD/vBqDgnChoOvVtVGscQQZ8eXT04uF8Xd6X0xstb0+HxN3NUWoUxhp" May 10 14:02:02 volumio volumio[702]: info: Initializing connection to go-librespot Websocket May 10 14:02:02 volumio go-librespot[31823]: time="2024-05-10T14:02:02+02:00" level=debug msg="new websocket client" May 10 14:02:02 volumio volumio[702]: info: Connection to go-librespot Websocket established May 10 14:02:02 volumio volumio[702]: verbose: New Socket.io Connection to 192.168.50.10 from 192.168.50.68 UA: okhttp/4.9.2 Total Clients: 6 May 10 14:02:02 volumio go-librespot[31823]: time="2024-05-10T14:02:02+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" May 10 14:02:02 volumio volumio[702]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 10 14:02:02 volumio volumio[702]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 10 14:02:02 volumio volumio[702]: info: CoreCommandRouter::volumioGetVisibleSources May 10 14:02:02 volumio volumio[702]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 10 14:02:02 volumio volumio[702]: info: CoreCommandRouter::volumioGetState May 10 14:02:02 volumio volumio[702]: info: CorePlayQueue::getTrack 0 May 10 14:02:02 volumio volumio[702]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 10 14:02:02 volumio volumio[702]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 10 14:02:02 volumio volumio[702]: info: Received Get System Info May 10 14:02:02 volumio volumio[702]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 10 14:02:02 volumio volumio[702]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 10 14:02:02 volumio volumio[702]: info: Discovery: Getting this device information May 10 14:02:02 volumio volumio[702]: info: CoreCommandRouter::volumioGetState May 10 14:02:02 volumio volumio[702]: info: CorePlayQueue::getTrack 0 May 10 14:02:02 volumio volumio[702]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 10 14:02:02 volumio volumio[702]: info: CoreCommandRouter::volumioGetState May 10 14:02:02 volumio volumio[702]: info: CorePlayQueue::getTrack 0 May 10 14:02:02 volumio go-librespot[31823]: time="2024-05-10T14:02:02+02:00" level=debug msg="completed keyexchange" May 10 14:02:02 volumio volumio[702]: info: Listing playlists May 10 14:02:02 volumio volumio[702]: info: CoreCommandRouter::volumioGetQueue May 10 14:02:02 volumio volumio[702]: info: CoreStateMachine::getQueue May 10 14:02:02 volumio volumio[702]: info: CorePlayQueue::getQueue May 10 14:02:02 volumio volumio[702]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 10 14:02:03 volumio go-librespot[31823]: time="2024-05-10T14:02:03+02:00" level=debug msg="completed challenge" May 10 14:02:03 volumio go-librespot[31823]: time="2024-05-10T14:02:03+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 10 14:02:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 10 14:02:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 10 14:02:03 volumio volumio[702]: info: Connection to go-librespot Websocket closed May 10 14:02:03 volumio volumio[702]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 10 14:02:03 volumio volumio[702]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 10 14:02:03 volumio volumio[702]: info: Discovery: Getting this device information May 10 14:02:03 volumio volumio[702]: info: CoreCommandRouter::volumioGetState May 10 14:02:03 volumio volumio[702]: info: CorePlayQueue::getTrack 0 May 10 14:02:03 volumio volumio[702]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 10 14:02:05 volumio volumio[702]: info: Getting Spotify volume May 10 14:02:05 volumio volumio[702]: (node:702) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 May 10 14:02:05 volumio volumio[702]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) May 10 14:02:05 volumio volumio[702]: (node:702) 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: 4605) May 10 14:02:05 volumio volumio[702]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 May 10 14:02:05 volumio volumio[702]: info: CoreCommandRouter::volumioGetState May 10 14:02:05 volumio volumio[702]: info: CorePlayQueue::getTrack 0 May 10 14:02:06 volumio volumio[702]: info: Initializing connection to go-librespot Websocket May 10 14:02:06 volumio volumio[702]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 10 14:02:06 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 10 14:02:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14124. May 10 14:02:06 volumio systemd[1]: Stopped go-librespot Daemon. May 10 14:02:06 volumio systemd[1]: Started go-librespot Daemon. May 10 14:02:06 volumio go-librespot[31831]: Librespot-go daemon starting... May 10 14:02:06 volumio go-librespot[31831]: time="2024-05-10T14:02:06+02:00" level=info msg="generated new device id: b2457de56c7ebe69eb39ec4bcc503ba8ce41e220" May 10 14:02:06 volumio go-librespot[31831]: time="2024-05-10T14:02:06+02:00" level=debug msg="stored credentials found for cspxgxr4w2nqbsxykzro5zm83" May 10 14:02:06 volumio volumio[702]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 10 14:02:06 volumio volumio[702]: info: Received Get System Info May 10 14:02:06 volumio volumio[702]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 10 14:02:06 volumio volumio[702]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 10 14:02:06 volumio volumio[702]: info: Discovery: Getting this device information May 10 14:02:06 volumio volumio[702]: info: CoreCommandRouter::volumioGetState May 10 14:02:06 volumio volumio[702]: info: CorePlayQueue::getTrack 0 May 10 14:02:06 volumio volumio[702]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 10 14:02:06 volumio go-librespot[31831]: time="2024-05-10T14:02:06+02:00" level=debug msg="obtained new client token: AAC0IZKiBTrPYlY3ewk1VbT2hufrDa55+mgvjAnXkSuQAsNbzUo+WAxWNGEMMaRWAMyb40BuOhLRVXYm7xO4X3rENuqqwsOVK4IYJFBtNKiwjgXFrO9KHk4JKjBmzTW6Z4f0FX+93nO0zFc1pL1JITHx76lnookQ3yY1u1FG2ECUKfTb8c/BbX1fcJOr6xe4RghXZBvNC5dQ/rBxqyUDnZs48Fh9ZjiJGUYopDunl8bMgopiKwnZECJOHoJGsLAV" May 10 14:02:08 volumio go-librespot[31831]: time="2024-05-10T14:02:08+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" May 10 14:02:08 volumio go-librespot[31831]: time="2024-05-10T14:02:08+02:00" level=debug msg="completed keyexchange" May 10 14:02:08 volumio go-librespot[31831]: time="2024-05-10T14:02:08+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed solving challenge: failed login: BadCredentials" May 10 14:02:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 10 14:02:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 10 14:02:09 volumio volumio[702]: info: Initializing connection to go-librespot Websocket May 10 14:02:09 volumio volumio[702]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 10 14:02:09 volumio volumio[702]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri May 10 14:02:09 volumio volumio[702]: info: CURURI: music-library/NAS/Muzyka_NAS/Yello May 10 14:02:09 volumio volumio[702]: info: Preload queue cleared May 10 14:02:09 volumio volumio[702]: info: Preloading song: music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-01The Expert.flac May 10 14:02:09 volumio volumio[702]: info: Preloading song: music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-02You Better Hide (featuring Heidi Happy).flac May 10 14:02:09 volumio volumio[702]: info: Preloading song: music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-03Out Of Dawn.flac May 10 14:02:09 volumio volumio[702]: info: Preloading song: music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-04Bostich (Reflected).flac May 10 14:02:09 volumio volumio[702]: info: Preloading song: music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-05Till Tomorrow (featuring Till Broenner).flac May 10 14:02:09 volumio volumio[702]: info: Preloading song: music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-06Tangier Blue.flac May 10 14:02:09 volumio volumio[702]: info: Preloading song: music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-07Part Love.flac May 10 14:02:09 volumio volumio[702]: info: Preloading song: music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-08Friday Smile.flac May 10 14:02:09 volumio volumio[702]: info: Preloading song: music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-09Kiss In Blue (featuring Heidi Happy).flac May 10 14:02:09 volumio volumio[702]: info: Preloading song: music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-10Vertical Vision (featuring Till Broenner).flac May 10 14:02:09 volumio volumio[702]: info: Preloading song: music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-11Trackless Deep.flac May 10 14:02:09 volumio volumio[702]: info: Preloading song: music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-12Stay (featuring Heidi Happy).flac May 10 14:02:09 volumio volumio[702]: info: Preloading song: music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-13Electric Frame (featuring Till Broenner).flac May 10 14:02:09 volumio volumio[702]: info: Preloading song: music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-14Takla Makan (featuring Dorothee Oberlinger).flac May 10 14:02:09 volumio volumio[702]: info: Exploding uri music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-01The Expert.flac in service mpd May 10 14:02:09 volumio volumio[702]: info: Exploding uri music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-02You Better Hide (featuring Heidi Happy).flac in service mpd May 10 14:02:09 volumio volumio[702]: info: Exploding uri music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-03Out Of Dawn.flac in service mpd May 10 14:02:09 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=//extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2FYELLOTouch%20Yello-01The%20Expert.flac&metadata=false May 10 14:02:09 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-01The Expert.flac May 10 14:02:09 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=//extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2FYELLOTouch%20Yello-02You%20Better%20Hide%20(featuring%20Heidi%20Happy).flac&metadata=false May 10 14:02:09 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-02You Better Hide (featuring Heidi Happy).flac May 10 14:02:09 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=//extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2FYELLOTouch%20Yello-03Out%20Of%20Dawn.flac&metadata=false May 10 14:02:09 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-03Out Of Dawn.flac May 10 14:02:09 volumio volumio[702]: info: Exploding uri music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-04Bostich (Reflected).flac in service mpd May 10 14:02:09 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=//extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2FYELLOTouch%20Yello-04Bostich%20(Reflected).flac&metadata=false May 10 14:02:09 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-04Bostich (Reflected).flac May 10 14:02:09 volumio volumio[702]: info: Exploding uri music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-05Till Tomorrow (featuring Till Broenner).flac in service mpd May 10 14:02:09 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=//extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2FYELLOTouch%20Yello-05Till%20Tomorrow%20(featuring%20Till%20Broenner).flac&metadata=false May 10 14:02:09 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-05Till Tomorrow (featuring Till Broenner).flac May 10 14:02:09 volumio volumio[702]: info: Exploding uri music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-06Tangier Blue.flac in service mpd May 10 14:02:09 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=//extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2FYELLOTouch%20Yello-06Tangier%20Blue.flac&metadata=false May 10 14:02:09 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-06Tangier Blue.flac May 10 14:02:09 volumio volumio[702]: info: Exploding uri music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-07Part Love.flac in service mpd May 10 14:02:10 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=//extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2FYELLOTouch%20Yello-07Part%20Love.flac&metadata=false May 10 14:02:10 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-07Part Love.flac May 10 14:02:10 volumio volumio[702]: info: Exploding uri music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-08Friday Smile.flac in service mpd May 10 14:02:10 volumio volumio[702]: info: Exploding uri music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-09Kiss In Blue (featuring Heidi Happy).flac in service mpd May 10 14:02:10 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=//extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2FYELLOTouch%20Yello-08Friday%20Smile.flac&metadata=false May 10 14:02:10 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-08Friday Smile.flac May 10 14:02:10 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=//extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2FYELLOTouch%20Yello-09Kiss%20In%20Blue%20(featuring%20Heidi%20Happy).flac&metadata=false May 10 14:02:10 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-09Kiss In Blue (featuring Heidi Happy).flac May 10 14:02:10 volumio volumio[702]: info: Exploding uri music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-10Vertical Vision (featuring Till Broenner).flac in service mpd May 10 14:02:10 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=//extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2FYELLOTouch%20Yello-10Vertical%20Vision%20(featuring%20Till%20Broenner).flac&metadata=false May 10 14:02:10 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-10Vertical Vision (featuring Till Broenner).flac May 10 14:02:10 volumio volumio[702]: info: Exploding uri music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-11Trackless Deep.flac in service mpd May 10 14:02:10 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=//extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2FYELLOTouch%20Yello-11Trackless%20Deep.flac&metadata=false May 10 14:02:10 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-11Trackless Deep.flac May 10 14:02:10 volumio volumio[702]: info: Exploding uri music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-12Stay (featuring Heidi Happy).flac in service mpd May 10 14:02:10 volumio volumio[702]: info: Exploding uri music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-13Electric Frame (featuring Till Broenner).flac in service mpd May 10 14:02:10 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=//extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2FYELLOTouch%20Yello-12Stay%20(featuring%20Heidi%20Happy).flac&metadata=false May 10 14:02:10 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-12Stay (featuring Heidi Happy).flac May 10 14:02:10 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=//extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2FYELLOTouch%20Yello-13Electric%20Frame%20(featuring%20Till%20Broenner).flac&metadata=false May 10 14:02:10 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-13Electric Frame (featuring Till Broenner).flac May 10 14:02:10 volumio volumio[702]: info: Exploding uri music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-14Takla Makan (featuring Dorothee Oberlinger).flac in service mpd May 10 14:02:10 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=//extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2FYELLOTouch%20Yello-14Takla%20Makan%20(featuring%20Dorothee%20Oberlinger).flac&metadata=false May 10 14:02:10 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-14Takla Makan (featuring Dorothee Oberlinger).flac May 10 14:02:11 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 10 14:02:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14125. May 10 14:02:11 volumio systemd[1]: Stopped go-librespot Daemon. May 10 14:02:11 volumio systemd[1]: Started go-librespot Daemon. May 10 14:02:11 volumio go-librespot[31840]: Librespot-go daemon starting... May 10 14:02:11 volumio go-librespot[31840]: time="2024-05-10T14:02:11+02:00" level=info msg="generated new device id: ec5128e49108d62eb9bbd844b3fc269f605a68a0" May 10 14:02:11 volumio go-librespot[31840]: time="2024-05-10T14:02:11+02:00" level=debug msg="stored credentials found for cspxgxr4w2nqbsxykzro5zm83" May 10 14:02:11 volumio go-librespot[31840]: time="2024-05-10T14:02:11+02:00" level=debug msg="obtained new client token: AACj5iJxiliQIaRVfw9wg/ucVklXfP2L7PXHNI6x8xD6zxjxyzf5oRTp4gtdxKLbalobr16JcnrsfWiLc8udrQSTWdINgSIkC8/Tw0hwJXhj8b45sQqJ33BwNLiUyyxLK9QEMsHwJDINZ9lWCrp9hRumUkctk78kIsiUUvktnn3dhNEHcp9AZ10ProWkuGkp4tyVOU7oJ9qjKGrp6Q1rdNpQmC/UAu/t/G/YrBqG8wU7ceUB5PJFpLqgeR7BVZ13" May 10 14:02:12 volumio go-librespot[31840]: time="2024-05-10T14:02:12+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" May 10 14:02:12 volumio go-librespot[31840]: time="2024-05-10T14:02:12+02:00" level=debug msg="completed keyexchange" May 10 14:02:12 volumio volumio[702]: info: Initializing connection to go-librespot Websocket May 10 14:02:12 volumio go-librespot[31840]: time="2024-05-10T14:02:12+02:00" level=debug msg="new websocket client" May 10 14:02:12 volumio volumio[702]: info: Connection to go-librespot Websocket established May 10 14:02:12 volumio go-librespot[31840]: time="2024-05-10T14:02:12+02:00" level=debug msg="completed challenge" May 10 14:02:12 volumio go-librespot[31840]: time="2024-05-10T14:02:12+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 10 14:02:12 volumio volumio[702]: info: Connection to go-librespot Websocket closed May 10 14:02:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 10 14:02:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 10 14:02:15 volumio volumio[702]: info: Getting Spotify volume May 10 14:02:15 volumio volumio[702]: (node:702) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 May 10 14:02:15 volumio volumio[702]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) May 10 14:02:15 volumio volumio[702]: (node:702) 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: 4606) May 10 14:02:15 volumio volumio[702]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 May 10 14:02:15 volumio volumio[702]: info: CoreCommandRouter::volumioGetState May 10 14:02:15 volumio volumio[702]: info: CorePlayQueue::getTrack 0 May 10 14:02:15 volumio volumio[702]: info: Initializing connection to go-librespot Websocket May 10 14:02:15 volumio volumio[702]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 10 14:02:15 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 10 14:02:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14126. May 10 14:02:15 volumio systemd[1]: Stopped go-librespot Daemon. May 10 14:02:15 volumio systemd[1]: Started go-librespot Daemon. May 10 14:02:15 volumio go-librespot[31848]: Librespot-go daemon starting... May 10 14:02:16 volumio go-librespot[31848]: time="2024-05-10T14:02:16+02:00" level=info msg="generated new device id: d2a34900bb9486d34ae5f51a95c99cf2669bcccd" May 10 14:02:16 volumio go-librespot[31848]: time="2024-05-10T14:02:16+02:00" level=debug msg="stored credentials found for cspxgxr4w2nqbsxykzro5zm83" May 10 14:02:16 volumio go-librespot[31848]: time="2024-05-10T14:02:16+02:00" level=debug msg="obtained new client token: AACVtVJonLkVMC7oFXSllB5kODfNmoxMqCAhQ2JILX8ZWncvX9r9TaIDUi66yHLASZNPZuI5fEJgHprwEjORxmzCMJ8lj6R1I2iDKauWBrYlKpKwq/3jl0Wwbkp8DRs0/bZfOW9JwKsYu9y09UpEYNVtkp/nQSiMOFmNbQGd3WGTSnWi20Ker8wyQCfRmGcXkBEVVz1R5mW69owG6nSfOzh/QiWGURGqapK4SVTCfrYxEwglXSHK/Am5mTYkvg==" May 10 14:02:16 volumio go-librespot[31848]: time="2024-05-10T14:02:16+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" May 10 14:02:16 volumio go-librespot[31848]: time="2024-05-10T14:02:16+02:00" level=debug msg="completed keyexchange" May 10 14:02:16 volumio go-librespot[31848]: time="2024-05-10T14:02:16+02:00" level=debug msg="completed challenge" May 10 14:02:17 volumio go-librespot[31848]: time="2024-05-10T14:02:17+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 10 14:02:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 10 14:02:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 10 14:02:18 volumio volumio[702]: info: Preload queue cleared May 10 14:02:18 volumio volumio[702]: info: CoreCommandRouter::volumioReplaceandPlayItems May 10 14:02:18 volumio volumio[702]: info: CoreStateMachine::ClearQueue May 10 14:02:18 volumio volumio[702]: info: CoreStateMachine::stop May 10 14:02:18 volumio volumio[702]: info: CoreStateMachine::setConsumeUpdateService undefined May 10 14:02:18 volumio volumio[702]: info: CorePlayQueue::clearPlayQueue May 10 14:02:18 volumio volumio[702]: info: CorePlayQueue::saveQueue May 10 14:02:18 volumio volumio[702]: info: CoreCommandRouter::volumioPushQueue May 10 14:02:18 volumio volumio[702]: info: CoreStateMachine::addQueueItems May 10 14:02:18 volumio volumio[702]: info: CorePlayQueue::addQueueItems May 10 14:02:18 volumio volumio[702]: info: Preload queue cleared May 10 14:02:18 volumio volumio[702]: info: Adding Item to queue: music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-01The Expert.flac May 10 14:02:18 volumio volumio[702]: info: Using cached record of: music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-01The Expert.flac May 10 14:02:18 volumio volumio[702]: info: Adding Item to queue: music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-02You Better Hide (featuring Heidi Happy).flac May 10 14:02:18 volumio volumio[702]: info: Using cached record of: music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-02You Better Hide (featuring Heidi Happy).flac May 10 14:02:18 volumio volumio[702]: info: Adding Item to queue: music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-03Out Of Dawn.flac May 10 14:02:18 volumio volumio[702]: info: Using cached record of: music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-03Out Of Dawn.flac May 10 14:02:18 volumio volumio[702]: info: Adding Item to queue: music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-04Bostich (Reflected).flac May 10 14:02:18 volumio volumio[702]: info: Using cached record of: music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-04Bostich (Reflected).flac May 10 14:02:18 volumio volumio[702]: info: Adding Item to queue: music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-05Till Tomorrow (featuring Till Broenner).flac May 10 14:02:18 volumio volumio[702]: info: Using cached record of: music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-05Till Tomorrow (featuring Till Broenner).flac May 10 14:02:18 volumio volumio[702]: info: Adding Item to queue: music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-06Tangier Blue.flac May 10 14:02:18 volumio volumio[702]: info: Using cached record of: music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-06Tangier Blue.flac May 10 14:02:18 volumio volumio[702]: info: Adding Item to queue: music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-07Part Love.flac May 10 14:02:18 volumio volumio[702]: info: Using cached record of: music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-07Part Love.flac May 10 14:02:18 volumio volumio[702]: info: Adding Item to queue: music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-08Friday Smile.flac May 10 14:02:18 volumio volumio[702]: info: Using cached record of: music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-08Friday Smile.flac May 10 14:02:18 volumio volumio[702]: info: Adding Item to queue: music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-09Kiss In Blue (featuring Heidi Happy).flac May 10 14:02:18 volumio volumio[702]: info: Using cached record of: music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-09Kiss In Blue (featuring Heidi Happy).flac May 10 14:02:18 volumio volumio[702]: info: Adding Item to queue: music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-10Vertical Vision (featuring Till Broenner).flac May 10 14:02:18 volumio volumio[702]: info: Using cached record of: music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-10Vertical Vision (featuring Till Broenner).flac May 10 14:02:18 volumio volumio[702]: info: Adding Item to queue: music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-11Trackless Deep.flac May 10 14:02:18 volumio volumio[702]: info: Using cached record of: music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-11Trackless Deep.flac May 10 14:02:18 volumio volumio[702]: info: Adding Item to queue: music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-12Stay (featuring Heidi Happy).flac May 10 14:02:18 volumio volumio[702]: info: Using cached record of: music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-12Stay (featuring Heidi Happy).flac May 10 14:02:18 volumio volumio[702]: info: Adding Item to queue: music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-13Electric Frame (featuring Till Broenner).flac May 10 14:02:18 volumio volumio[702]: info: Using cached record of: music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-13Electric Frame (featuring Till Broenner).flac May 10 14:02:18 volumio volumio[702]: info: Adding Item to queue: music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-14Takla Makan (featuring Dorothee Oberlinger).flac May 10 14:02:18 volumio volumio[702]: info: Using cached record of: music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-14Takla Makan (featuring Dorothee Oberlinger).flac May 10 14:02:18 volumio volumio[702]: info: Adding Item to queue: music-library/NAS/Muzyka_NAS/Yello/1980 Solid Pleasure May 10 14:02:18 volumio volumio[702]: info: Exploding uri music-library/NAS/Muzyka_NAS/Yello/1980 Solid Pleasure in service mpd May 10 14:02:18 volumio volumio[702]: info: Adding Item to queue: music-library/NAS/Muzyka_NAS/Yello/1981 Claro Que Si May 10 14:02:18 volumio volumio[702]: info: Exploding uri music-library/NAS/Muzyka_NAS/Yello/1981 Claro Que Si in service mpd May 10 14:02:18 volumio volumio[702]: info: Adding Item to queue: music-library/NAS/Muzyka_NAS/Yello/1983 HD You Gotta Say Yes To Another Excess May 10 14:02:18 volumio volumio[702]: info: Exploding uri music-library/NAS/Muzyka_NAS/Yello/1983 HD You Gotta Say Yes To Another Excess in service mpd May 10 14:02:18 volumio volumio[702]: info: Adding Item to queue: music-library/NAS/Muzyka_NAS/Yello/1983 You Gotta Say Yes To Another Excess May 10 14:02:18 volumio volumio[702]: info: Exploding uri music-library/NAS/Muzyka_NAS/Yello/1983 You Gotta Say Yes To Another Excess in service mpd May 10 14:02:18 volumio volumio[702]: info: Adding Item to queue: music-library/NAS/Muzyka_NAS/Yello/1985 Stella May 10 14:02:18 volumio volumio[702]: info: Exploding uri music-library/NAS/Muzyka_NAS/Yello/1985 Stella in service mpd May 10 14:02:18 volumio volumio[702]: info: Adding Item to queue: music-library/NAS/Muzyka_NAS/Yello/1987 One Second May 10 14:02:18 volumio volumio[702]: info: Exploding uri music-library/NAS/Muzyka_NAS/Yello/1987 One Second in service mpd May 10 14:02:18 volumio volumio[702]: info: Adding Item to queue: music-library/NAS/Muzyka_NAS/Yello/1988 Flag May 10 14:02:18 volumio volumio[702]: info: Exploding uri music-library/NAS/Muzyka_NAS/Yello/1988 Flag in service mpd May 10 14:02:18 volumio volumio[702]: info: Adding Item to queue: music-library/NAS/Muzyka_NAS/Yello/1994 Zebra May 10 14:02:18 volumio volumio[702]: info: Exploding uri music-library/NAS/Muzyka_NAS/Yello/1994 Zebra in service mpd May 10 14:02:18 volumio volumio[702]: info: Adding Item to queue: music-library/NAS/Muzyka_NAS/Yello/2009 Touch May 10 14:02:18 volumio volumio[702]: info: Exploding uri music-library/NAS/Muzyka_NAS/Yello/2009 Touch in service mpd May 10 14:02:18 volumio volumio[702]: info: Adding Item to queue: music-library/NAS/Muzyka_NAS/Yello/2014 Convergence Malia & Boris Blank May 10 14:02:18 volumio volumio[702]: info: Exploding uri music-library/NAS/Muzyka_NAS/Yello/2014 Convergence Malia & Boris Blank in service mpd May 10 14:02:18 volumio volumio[702]: info: Adding Item to queue: music-library/NAS/Muzyka_NAS/Yello/2016 Toy May 10 14:02:18 volumio volumio[702]: info: Exploding uri music-library/NAS/Muzyka_NAS/Yello/2016 Toy in service mpd May 10 14:02:18 volumio volumio[702]: info: Adding Item to queue: music-library/NAS/Muzyka_NAS/Yello/Boris Blank - Electrified Box [INK3] [2014] May 10 14:02:18 volumio volumio[702]: info: Exploding uri music-library/NAS/Muzyka_NAS/Yello/Boris Blank - Electrified Box [INK3] [2014] in service mpd May 10 14:02:18 volumio volumio[702]: info: Adding Item to queue: music-library/NAS/Muzyka_NAS/Yello/Boris Blank - Resonance - 2024 (24-48) May 10 14:02:18 volumio volumio[702]: info: Exploding uri music-library/NAS/Muzyka_NAS/Yello/Boris Blank - Resonance - 2024 (24-48) in service mpd May 10 14:02:18 volumio volumio[702]: info: Adding Item to queue: music-library/NAS/Muzyka_NAS/Yello/Jungle Bill May 10 14:02:18 volumio volumio[702]: info: Exploding uri music-library/NAS/Muzyka_NAS/Yello/Jungle Bill in service mpd May 10 14:02:18 volumio volumio[702]: info: Initializing connection to go-librespot Websocket May 10 14:02:18 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=Yello/Solid%20Pleasure%201980%20Yello%20Remastered%202005/extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2F1980%20Solid%20Pleasure%2F01-Yello-Bimbo.flac&metadata=false May 10 14:02:18 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/1980 Solid Pleasure/01-Yello-Bimbo.flac May 10 14:02:18 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=Yello/Solid%20Pleasure%201980%20Yello%20Remastered%202005/extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2F1980%20Solid%20Pleasure%2F02-Yello-Night%20Flanger.flac&metadata=false May 10 14:02:18 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/1980 Solid Pleasure/02-Yello-Night Flanger.flac May 10 14:02:18 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=Yello/Solid%20Pleasure%201980%20Yello%20Remastered%202005/extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2F1980%20Solid%20Pleasure%2F03-Yello-Reverse%20Lion.flac&metadata=false May 10 14:02:18 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/1980 Solid Pleasure/03-Yello-Reverse Lion.flac May 10 14:02:18 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=Yello/Solid%20Pleasure%201980%20Yello%20Remastered%202005/extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2F1980%20Solid%20Pleasure%2F04-Yello-Downtown%20Samba.flac&metadata=false May 10 14:02:18 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/1980 Solid Pleasure/04-Yello-Downtown Samba.flac May 10 14:02:18 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=Yello/Solid%20Pleasure%201980%20Yello%20Remastered%202005/extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2F1980%20Solid%20Pleasure%2F05-Yello-Magneto.flac&metadata=false May 10 14:02:18 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/1980 Solid Pleasure/05-Yello-Magneto.flac May 10 14:02:18 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=Yello/Solid%20Pleasure%201980%20Yello%20Remastered%202005/extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2F1980%20Solid%20Pleasure%2F06-Yello-Massage.flac&metadata=false May 10 14:02:18 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/1980 Solid Pleasure/06-Yello-Massage.flac May 10 14:02:18 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=Yello/Solid%20Pleasure%201980%20Yello%20Remastered%202005/extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2F1980%20Solid%20Pleasure%2F07-Yello-Assistant%60s%20Cry.flac&metadata=false May 10 14:02:18 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/1980 Solid Pleasure/07-Yello-Assistant`s Cry.flac May 10 14:02:18 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=Yello/Solid%20Pleasure%201980%20Yello%20Remastered%202005/extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2F1980%20Solid%20Pleasure%2F08-Yello-Bostich.flac&metadata=false May 10 14:02:18 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/1980 Solid Pleasure/08-Yello-Bostich.flac May 10 14:02:18 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=Yello/Solid%20Pleasure%201980%20Yello%20Remastered%202005/extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2F1980%20Solid%20Pleasure%2F09-Yello-Rock%20Stop.flac&metadata=false May 10 14:02:18 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/1980 Solid Pleasure/09-Yello-Rock Stop.flac May 10 14:02:18 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=Yello/Solid%20Pleasure%201980%20Yello%20Remastered%202005/extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2F1980%20Solid%20Pleasure%2F10-Yello-Coast%20to%20Polka.flac&metadata=false May 10 14:02:18 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/1980 Solid Pleasure/10-Yello-Coast to Polka.flac May 10 14:02:18 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=Yello/Solid%20Pleasure%201980%20Yello%20Remastered%202005/extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2F1980%20Solid%20Pleasure%2F11-Yello-Blue%20Green.flac&metadata=false May 10 14:02:18 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/1980 Solid Pleasure/11-Yello-Blue Green.flac May 10 14:02:18 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=Yello/Solid%20Pleasure%201980%20Yello%20Remastered%202005/extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2F1980%20Solid%20Pleasure%2F12-Yello-Eternal%20Legs.flac&metadata=false May 10 14:02:18 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/1980 Solid Pleasure/12-Yello-Eternal Legs.flac May 10 14:02:18 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=Yello/Solid%20Pleasure%201980%20Yello%20Remastered%202005/extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2F1980%20Solid%20Pleasure%2F13-Yello-Stanztrigger.flac&metadata=false May 10 14:02:18 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/1980 Solid Pleasure/13-Yello-Stanztrigger.flac May 10 14:02:18 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=Yello/Solid%20Pleasure%201980%20Yello%20Remastered%202005/extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2F1980%20Solid%20Pleasure%2F14-Yello-Bananas%20to%20the%20Beat.flac&metadata=false May 10 14:02:18 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/1980 Solid Pleasure/14-Yello-Bananas to the Beat.flac May 10 14:02:18 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=Yello/Solid%20Pleasure%201980%20Yello%20Remastered%202005/extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2F1980%20Solid%20Pleasure%2F15-Yello-Thrill%20Wave.flac&metadata=false May 10 14:02:18 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/1980 Solid Pleasure/15-Yello-Thrill Wave.flac May 10 14:02:18 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=Yello/Solid%20Pleasure%201980%20Yello%20Remastered%202005/extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2F1980%20Solid%20Pleasure%2F16-Yello-I.T.%20Splash.flac&metadata=false May 10 14:02:18 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/1980 Solid Pleasure/16-Yello-I.T. Splash.flac May 10 14:02:18 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=Yello/Solid%20Pleasure%201980%20Yello%20Remastered%202005/extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2F1980%20Solid%20Pleasure%2F17-Yello-Gluehead.flac&metadata=false May 10 14:02:18 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/1980 Solid Pleasure/17-Yello-Gluehead.flac May 10 14:02:18 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=Yello/Solid%20Pleasure%201980%20Yello%20Remastered%202005/extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2F1980%20Solid%20Pleasure%2F18-Yello-Smirak's%20Train.flac&metadata=false May 10 14:02:18 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/1980 Solid Pleasure/18-Yello-Smirak's Train.flac May 10 14:02:18 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=Yello/Solid%20Pleasure%201980%20Yello%20Remastered%202005/extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2F1980%20Solid%20Pleasure%2F19-Yello-Bostich%20(N'est-ce%20pas).flac&metadata=false May 10 14:02:18 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/1980 Solid Pleasure/19-Yello-Bostich (N'est-ce pas).flac May 10 14:02:18 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=Yello/Claro%20Que%20Si/extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2F1981%20Claro%20Que%20Si%2F01-daily%20disco.flac&metadata=false May 10 14:02:18 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/1981 Claro Que Si/01-daily disco.flac May 10 14:02:18 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=Yello/Claro%20Que%20Si/extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2F1981%20Claro%20Que%20Si%2F02-no%20more%20roger.flac&metadata=false May 10 14:02:18 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/1981 Claro Que Si/02-no more roger.flac May 10 14:02:18 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=Yello/Claro%20Que%20Si/extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2F1981%20Claro%20Que%20Si%2F03-take%20it%20all.flac&metadata=false May 10 14:02:18 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/1981 Claro Que Si/03-take it all.flac May 10 14:02:18 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=Yello/Claro%20Que%20Si/extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2F1981%20Claro%20Que%20Si%2F04-the%20evening's%20young.flac&metadata=false May 10 14:02:18 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/1981 Claro Que Si/04-the evening's young.flac May 10 14:02:18 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=Yello/Claro%20Que%20Si/extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2F1981%20Claro%20Que%20Si%2F05-she's%20got%20a%20gun.flac&metadata=false May 10 14:02:18 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/1981 Claro Que Si/05-she's got a gun.flac May 10 14:02:18 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=Yello/Claro%20Que%20Si/extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2F1981%20Claro%20Que%20Si%2F06-ballet%20mecanique.flac&metadata=false May 10 14:02:18 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/1981 Claro Que Si/06-ballet mecanique.flac May 10 14:02:18 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=Yello/Claro%20Que%20Si/extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2F1981%20Claro%20Que%20Si%2F07-ouad%20el%20habib.flac&metadata=false May 10 14:02:18 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/1981 Claro Que Si/07-ouad el habib.flac May 10 14:02:18 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=Yello/Claro%20Que%20Si/extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2F1981%20Claro%20Que%20Si%2F08-the%20lorry.flac&metadata=false May 10 14:02:18 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/1981 Claro Que Si/08-the lorry.flac May 10 14:02:18 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=Yello/Claro%20Que%20Si/extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2F1981%20Claro%20Que%20Si%2F09-homer%20hossa.flac&metadata=false May 10 14:02:18 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/1981 Claro Que Si/09-homer hossa.flac May 10 14:02:18 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=Yello/Claro%20Que%20Si/extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2F1981%20Claro%20Que%20Si%2F10-pinball%20cha%20cha.flac&metadata=false May 10 14:02:18 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/1981 Claro Que Si/10-pinball cha cha.flac May 10 14:02:18 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=Yello/Claro%20Que%20Si/extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2F1981%20Claro%20Que%20Si%2F11-tub%20dub.flac&metadata=false May 10 14:02:18 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/1981 Claro Que Si/11-tub dub.flac May 10 14:02:18 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=Yello/Claro%20Que%20Si/extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2F1981%20Claro%20Que%20Si%2F12-she's%20got%20a%20gun%20(live%20at%20the%20palladium%20ny%20sep.%201985).flac&metadata=false May 10 14:02:18 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/1981 Claro Que Si/12-she's got a gun (live at the palladium ny sep. 1985).flac May 10 14:02:18 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=Yello/Claro%20Que%20Si/extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2F1981%20Claro%20Que%20Si%2F13-daily%20disco%20(1985%20version).flac&metadata=false May 10 14:02:18 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/1981 Claro Que Si/13-daily disco (1985 version).flac May 10 14:02:18 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=Yello/Claro%20Que%20Si/extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2F1981%20Claro%20Que%20Si%2F14-the%20evening's%20young%20(1985%20version).flac&metadata=false May 10 14:02:18 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/1981 Claro Que Si/14-the evening's young (1985 version).flac May 10 14:02:18 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=Yello/Claro%20Que%20Si/extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2F1981%20Claro%20Que%20Si%2F15-pinball%20cha%20cha%20(12'%20mix).flac&metadata=false May 10 14:02:18 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/1981 Claro Que Si/15-pinball cha cha (12' mix).flac May 10 14:02:18 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=Yello/Claro%20Que%20Si/extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2F1981%20Claro%20Que%20Si%2F16-desire%20for%20desire.flac&metadata=false May 10 14:02:18 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/1981 Claro Que Si/16-desire for desire.flac May 10 14:02:18 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=//extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2F1983%20HD%20You%20Gotta%20Say%20Yes%20To%20Another%20Excess%2FYello%20-%20You%20Gotta%20Say%20Yes%20To%20Another%20Excess.flac&metadata=false May 10 14:02:18 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/1983 HD You Gotta Say Yes To Another Excess/Yello - You Gotta Say Yes To Another Excess.flac May 10 14:02:18 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=Yello%20/You%20Gotta%20Say%20Yes%20To%20Another%20Excess/extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2F1983%20HD%20You%20Gotta%20Say%20Yes%20To%20Another%20Excess%2FYello%20-%20You%20Gotta%20Say%20Yes%20To%20Another%20Excess.wav.cue&metadata=false May 10 14:02:18 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/1983 HD You Gotta Say Yes To Another Excess/Yello - You Gotta Say Yes To Another Excess.wav.cue May 10 14:02:18 volumio volumio[702]: info: ALBUMART /albumart?cacheid=952&web=Yello%20/You%20Gotta%20Say%20Yes%20To%20Another%20Excess/extralarge&path=%2Fmnt%2FNAS%2FMuzyka_NAS%2FYello%2F1983%20HD%20You%20Gotta%20Say%20Yes%20To%20Another%20Excess%2FYello%20-%20You%20Gotta%20Say%20Yes%20To%20Another%20Excess.wav.cue&metadata=false May 10 14:02:18 volumio volumio[702]: info: URI /mnt/NAS/Muzyka_NAS/Yello/1983 HD You Gotta Say Yes To Another Excess/Yello - You Gotta Say Yes To Another Excess.wav.cue May 10 14:02:18 volumio volumio[702]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 10 14:02:18 volumio volumio[702]: Error: Unable to resolve or reject the same promise twice May 10 14:02:18 volumio volumio[702]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) May 10 14:02:18 volumio volumio[702]: at /volumio/app/plugins/music_service/mpd/index.js:2568:21 May 10 14:02:18 volumio volumio[702]: at MpdClient.handleMessage (/volumio/app/plugins/music_service/mpd/lib/mpd.js:77:3) May 10 14:02:18 volumio volumio[702]: at MpdClient.receive (/volumio/app/plugins/music_service/mpd/lib/mpd.js:68:12) May 10 14:02:18 volumio volumio[702]: at Socket. (/volumio/app/plugins/music_service/mpd/lib/mpd.js:43:12) May 10 14:02:18 volumio volumio[702]: at Socket.emit (events.js:315:20) May 10 14:02:18 volumio volumio[702]: at addChunk (internal/streams/readable.js:309:12) May 10 14:02:18 volumio volumio[702]: at readableAddChunk (internal/streams/readable.js:280:11) May 10 14:02:18 volumio volumio[702]: at Socket.Readable.push (internal/streams/readable.js:223:10) May 10 14:02:18 volumio volumio[702]: at Pipe.onStreamRead (internal/stream_base_commons.js:188:23) May 10 14:02:18 volumio volumio[702]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 10 14:02:19 volumio sudo[31866]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-05-10 14:01 May 10 14:02:19 volumio sudo[31866]: pam_unix(sudo:session): session opened for user root by (uid=0) May 10 14:02:19 volumio sudo[31866]: pam_unix(sudo:session): session closed for user root May 10 14:02:20 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 10 14:02:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14127. May 10 14:02:20 volumio systemd[1]: Stopped go-librespot Daemon. May 10 14:02:20 volumio systemd[1]: Started go-librespot Daemon. May 10 14:02:20 volumio go-librespot[31874]: Librespot-go daemon starting... May 10 14:02:20 volumio go-librespot[31874]: time="2024-05-10T14:02:20+02:00" level=info msg="generated new device id: 52ae9d60c1213efeed1e079ec4836db4f052311f" May 10 14:02:20 volumio go-librespot[31874]: time="2024-05-10T14:02:20+02:00" level=debug msg="stored credentials found for cspxgxr4w2nqbsxykzro5zm83" May 10 14:02:20 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE May 10 14:02:20 volumio volumio-remote-updater[470]: [2024-05-10 14:02:20] [error] handle_read_frame error: websocketpp.transport:7 (End of File) May 10 14:02:20 volumio volumio-remote-updater[470]: [2024-05-10 14:02:20] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] May 10 14:02:20 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. May 10 14:02:20 volumio systemd[1]: Started dynamicswap service. May 10 14:02:20 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. May 10 14:02:20 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 1. May 10 14:02:20 volumio systemd[1]: dynamicswap.service: Succeeded. May 10 14:02:20 volumio systemd[1]: Stopped Volumio Backend Module. May 10 14:02:20 volumio systemd[1]: Started Volumio Backend Module. May 10 14:02:20 volumio go-librespot[31874]: time="2024-05-10T14:02:20+02:00" level=debug msg="obtained new client token: AABqFaU8An5ol1socSe7U3KTjSTOPVKFWtOPZvSDQ9OsVBFK2UaHbJpScBASGJO5HUETOhyfFLelW0YoDPJoJd1nh30YXuxkTxCrL3tIhPwdcBjVblwoEDj+yWLF+QhrzWaqNMsReAyGqb4c5cwRkaN8QWG+9OB1uQFhH/wDSL3drrK9Bb2QXUMlZnyPMU0f6H1VkVEx9cDthAE/LAYVFUIsRG1wQx4McipaVo/6WxyMynZl1qsc4tlWSYLYPlRQ" May 10 14:02:20 volumio go-librespot[31874]: time="2024-05-10T14:02:20+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" May 10 14:02:20 volumio go-librespot[31874]: time="2024-05-10T14:02:20+02:00" level=debug msg="completed keyexchange" May 10 14:02:21 volumio go-librespot[31874]: time="2024-05-10T14:02:21+02:00" level=debug msg="completed challenge" May 10 14:02:21 volumio go-librespot[31874]: time="2024-05-10T14:02:21+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 10 14:02:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 10 14:02:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 10 14:02:22 volumio volumio[31889]: info: ------------------------------------------- May 10 14:02:22 volumio volumio[31889]: info: ----- Volumio3 ---- May 10 14:02:22 volumio volumio[31889]: info: ------------------------------------------- May 10 14:02:22 volumio volumio[31889]: info: ----- System startup ---- May 10 14:02:22 volumio volumio[31889]: info: ------------------------------------------- May 10 14:02:23 volumio volumio[31889]: info: MYVOLUMIO Environment detected May 10 14:02:23 volumio volumio[31889]: info: Plugin folders cleanup May 10 14:02:23 volumio volumio[31889]: info: Scanning into folder /volumio/app/plugins/ May 10 14:02:23 volumio volumio[31889]: info: Scanning category audio_interface May 10 14:02:23 volumio volumio[31889]: info: Scanning category miscellanea May 10 14:02:23 volumio volumio[31889]: info: Scanning category music_service May 10 14:02:23 volumio volumio[31889]: info: Scanning category plugins.json May 10 14:02:23 volumio volumio[31889]: info: Scanning category system_controller May 10 14:02:23 volumio volumio[31889]: info: Scanning category user_interface May 10 14:02:23 volumio volumio[31889]: info: Scanning into folder /data/plugins/ May 10 14:02:23 volumio volumio[31889]: info: Scanning category audio_interface May 10 14:02:23 volumio volumio[31889]: info: Scanning category music_service May 10 14:02:23 volumio volumio[31889]: info: Scanning category system_controller May 10 14:02:23 volumio volumio[31889]: info: Scanning category system_hardware May 10 14:02:23 volumio volumio[31889]: info: Plugin folders cleanup completed May 10 14:02:23 volumio volumio[31889]: info: ------------------------------------------- May 10 14:02:23 volumio volumio[31889]: info: ----- Core plugins startup ---- May 10 14:02:23 volumio volumio[31889]: info: ------------------------------------------- May 10 14:02:23 volumio volumio[31889]: info: Loading plugins from folder /volumio/app/plugins/ May 10 14:02:23 volumio volumio[31889]: info: Adding plugin upnp to MyMusic Plugins May 10 14:02:23 volumio volumio[31889]: info: Adding plugin airplay_emulation to MyMusic Plugins May 10 14:02:23 volumio volumio[31889]: info: Adding plugin upnp_browser to MyMusic Plugins May 10 14:02:23 volumio volumio[31889]: info: Loading plugins from folder /data/plugins/ May 10 14:02:23 volumio volumio[31889]: info: Loading plugin "system"... May 10 14:02:23 volumio volumio[31889]: info: Loading plugin "appearance"... May 10 14:02:24 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 10 14:02:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14128. May 10 14:02:24 volumio systemd[1]: Stopped go-librespot Daemon. May 10 14:02:24 volumio systemd[1]: Started go-librespot Daemon. May 10 14:02:24 volumio go-librespot[31909]: Librespot-go daemon starting... May 10 14:02:24 volumio go-librespot[31909]: time="2024-05-10T14:02:24+02:00" level=info msg="generated new device id: 991daab51e4d679a342b90b21effff18d637d875" May 10 14:02:24 volumio go-librespot[31909]: time="2024-05-10T14:02:24+02:00" level=debug msg="stored credentials found for cspxgxr4w2nqbsxykzro5zm83" May 10 14:02:24 volumio go-librespot[31909]: time="2024-05-10T14:02:24+02:00" level=debug msg="obtained new client token: AAA3RyKkE/We2XjVg5xh0PQrinCR6TX/EBQ8093ry38cznxKT6qEQGFCa4JJb6Knu5PYWCJ7Os+a7OA1GcqCEhasCU/uZo0R3wsKIijyDoC8PId9yFfCuhh/x8nhcyRB0BxAATvRR74XtjNT/My8r6AjpSIx+fVdZusCCDCNYgqc0u63eWgZ+r2pLM4My+zgYgH714k6/2R16V5IgV3IhzeTRXPaGAYlqehonCYaxf6nPl/Pa7RXZrUPPDJYCsST" May 10 14:02:24 volumio volumio[31889]: info: Loading plugin "network"... May 10 14:02:24 volumio volumio[31889]: info: Refreshing Cached IP Addresses May 10 14:02:24 volumio go-librespot[31909]: time="2024-05-10T14:02:24+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" May 10 14:02:24 volumio volumio[31889]: info: Loading plugin "services"... May 10 14:02:24 volumio sudo[31918]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 10 14:02:24 volumio sudo[31918]: pam_unix(sudo:session): session opened for user root by (uid=0) May 10 14:02:24 volumio sudo[31920]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 10 14:02:24 volumio sudo[31920]: pam_unix(sudo:session): session opened for user root by (uid=0) May 10 14:02:24 volumio volumio[31889]: info: Loading plugin "alsa_controller"... May 10 14:02:24 volumio sudo[31918]: pam_unix(sudo:session): session closed for user root May 10 14:02:24 volumio sudo[31920]: pam_unix(sudo:session): session closed for user root May 10 14:02:25 volumio go-librespot[31909]: time="2024-05-10T14:02:25+02:00" level=debug msg="completed keyexchange" May 10 14:02:25 volumio volumio[31889]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 10 14:02:25 volumio volumio[31889]: info: Loading plugin "wizard"... May 10 14:02:25 volumio volumio[31889]: info: Loading plugin "networkfs"... May 10 14:02:25 volumio volumio[31889]: info: Cannot mount NAS Muzyka_NAS at system boot, trial number 1 ,retrying in 5 seconds May 10 14:02:25 volumio volumio[31889]: info: Starting Udev Watcher for removable devices May 10 14:02:25 volumio volumio[31889]: info: Ignoring mount for partition: boot May 10 14:02:25 volumio volumio[31889]: info: Ignoring mount for partition: volumio May 10 14:02:25 volumio volumio[31889]: info: Ignoring mount for partition: volumio_data May 10 14:02:25 volumio volumio[31889]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 10 14:02:25 volumio volumio[31889]: info: Loading plugin "volumio_command_line_client"... May 10 14:02:25 volumio volumio[31889]: info: Loading plugin "upnp"... May 10 14:02:25 volumio volumio[31889]: info: [1715342545208] Starting Upmpd Daemon May 10 14:02:25 volumio volumio[31889]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 10 14:02:25 volumio volumio[31889]: info: Loading plugin "my_music"... May 10 14:02:25 volumio volumio[31889]: info: Loading plugin "mpd"... May 10 14:02:25 volumio volumio-remote-updater[470]: [2024-05-10 14:02:25] [connect] Successful connection May 10 14:02:25 volumio go-librespot[31909]: time="2024-05-10T14:02:25+02:00" level=debug msg="completed challenge" May 10 14:02:25 volumio go-librespot[31909]: time="2024-05-10T14:02:25+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 10 14:02:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 10 14:02:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 10 14:02:25 volumio volumio[31889]: info: Loading plugin "upnp_browser"... May 10 14:02:25 volumio volumio[31889]: info: Loading plugin "alarm-clock"... May 10 14:02:26 volumio volumio[31889]: info: Loading plugin "airplay_emulation"... May 10 14:02:26 volumio volumio[31889]: info: Starting Shairport Sync May 10 14:02:26 volumio volumio[31889]: info: Loading plugin "last_100"... May 10 14:02:26 volumio volumio[31889]: info: Loading plugin "webradio"... May 10 14:02:26 volumio volumio[31889]: info: Loading plugin "i2s_dacs"... May 10 14:02:26 volumio volumio[31889]: info: Loading plugin "volumiodiscovery"... May 10 14:02:26 volumio volumio[31889]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 10 14:02:26 volumio volumio[31889]: *** WARNING *** Please fix your application to use the native API of Avahi! May 10 14:02:26 volumio volumio[31889]: *** WARNING *** For more information see May 10 14:02:26 volumio node[31889]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 10 14:02:26 volumio volumio[31889]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 10 14:02:26 volumio volumio[31889]: *** WARNING *** Please fix your application to use the native API of Avahi! May 10 14:02:26 volumio volumio[31889]: *** WARNING *** For more information see May 10 14:02:26 volumio node[31889]: *** WARNING *** Please fix your application to use the native API of Avahi! May 10 14:02:26 volumio node[31889]: *** WARNING *** For more information see May 10 14:02:26 volumio node[31889]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 10 14:02:26 volumio node[31889]: *** WARNING *** Please fix your application to use the native API of Avahi! May 10 14:02:26 volumio node[31889]: *** WARNING *** For more information see May 10 14:02:26 volumio volumio[31889]: info: Applying required configuration parameters for plugin volumiodiscovery May 10 14:02:26 volumio volumio[31889]: info: Discovery: Started advertising with name: Volumio May 10 14:02:26 volumio volumio[31889]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 10 14:02:26 volumio volumio[31889]: info: Loading plugin "spop"... May 10 14:02:28 volumio volumio[31889]: info: Loading plugin "ytcr"... May 10 14:02:28 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 10 14:02:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14129. May 10 14:02:28 volumio systemd[1]: Stopped go-librespot Daemon. May 10 14:02:28 volumio systemd[1]: Started go-librespot Daemon. May 10 14:02:28 volumio go-librespot[31927]: Librespot-go daemon starting... May 10 14:02:28 volumio go-librespot[31927]: time="2024-05-10T14:02:28+02:00" level=info msg="generated new device id: 3f1fcb29265a961af4a7c054e62c3204427593ad" May 10 14:02:28 volumio go-librespot[31927]: time="2024-05-10T14:02:28+02:00" level=debug msg="stored credentials found for cspxgxr4w2nqbsxykzro5zm83" May 10 14:02:29 volumio go-librespot[31927]: time="2024-05-10T14:02:29+02:00" level=debug msg="obtained new client token: AADjXCKta08j63LjqxNbyDEwZcsg9WnC5Y6PXWl4gvIQvQksFSdp3h3o5hJf+uMBnAWQdk+8N5DfAcrG/Qlj0bkYtkC7irN2prwlocBzHiKrquJiDsl0lrMtGplmOtPKs0lpipLOXuLWUcNOtUf5hjS+Lx1yo+KFlNexwkyCdOJYP+QfN880z6GUM+OL1I8CpfsTCSlFaKU53We6/V3qn2YB5BJH70rOYGfoTiXTFNLhJODC4aWerb1/PNG51A==" May 10 14:02:29 volumio go-librespot[31927]: time="2024-05-10T14:02:29+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" May 10 14:02:29 volumio go-librespot[31927]: time="2024-05-10T14:02:29+02:00" level=debug msg="completed keyexchange" May 10 14:02:29 volumio go-librespot[31927]: time="2024-05-10T14:02:29+02:00" level=debug msg="completed challenge" May 10 14:02:29 volumio go-librespot[31927]: time="2024-05-10T14:02:29+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 10 14:02:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 10 14:02:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 10 14:02:30 volumio volumio[31889]: info: Loading plugin "ytmusic"... May 10 14:02:32 volumio volumio[31889]: info: Loading plugin "outputs"... May 10 14:02:32 volumio volumio[31889]: info: Loading plugin "albumart"... May 10 14:02:32 volumio volumio[31889]: info: Plugin example_plugin is not enabled May 10 14:02:32 volumio volumio[31889]: info: Loading plugin "inputs"... May 10 14:02:32 volumio volumio[31889]: info: Loading plugin "updater_comm"... May 10 14:02:32 volumio volumio[31889]: info: Plugin mpdemulation is not enabled May 10 14:02:32 volumio volumio[31889]: info: Loading plugin "rest_api"... May 10 14:02:32 volumio volumio[31889]: info: Loading plugin "websocket"... May 10 14:02:32 volumio volumio[31889]: info: Plugin fusiondsp is not enabled May 10 14:02:32 volumio volumio[31889]: info: Loading plugin "80s80s"... May 10 14:02:32 volumio volumio[31889]: Forking 3 albumart workers May 10 14:02:33 volumio volumio[31889]: info: Applying required configuration parameters for plugin 80s80s May 10 14:02:33 volumio volumio[31889]: info: [1715342553048] [80s80s] API delay: 30 May 10 14:02:33 volumio volumio[31889]: info: Loading plugin "rad357pl"... May 10 14:02:33 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 10 14:02:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14130. May 10 14:02:33 volumio systemd[1]: Stopped go-librespot Daemon. May 10 14:02:33 volumio systemd[1]: Started go-librespot Daemon. May 10 14:02:33 volumio go-librespot[32000]: Librespot-go daemon starting... May 10 14:02:33 volumio go-librespot[32000]: time="2024-05-10T14:02:33+02:00" level=info msg="generated new device id: 94e9300e20dbfb77e3b52090ad8d91d90f1039a8" May 10 14:02:33 volumio go-librespot[32000]: time="2024-05-10T14:02:33+02:00" level=debug msg="stored credentials found for cspxgxr4w2nqbsxykzro5zm83" May 10 14:02:33 volumio go-librespot[32000]: time="2024-05-10T14:02:33+02:00" level=debug msg="obtained new client token: AAC2Fo+j/JcimYwAUsRiM6JdjWHcIm4U8yTjrt4buXI5TpM3eQnP6ejJoFr95WZ4+mHVi+bFZD3JLSfT1EJxxp5HKLAc2/yfnKu0CbBn+LapEv+XnnVoZs+Z+Dyi7CCoaj7nHJoHS+Q5hLJ+t39dCO1XNLj0W1c8RTGxbJz138O/y+p89AesnkYz+7yxdc0hU1WFkM2tS7/wsS9rdeO+Lw35HlPw0iSuq/PEVuxQWG+eBSvmMdM5Wp4KtfU6E7nw" May 10 14:02:33 volumio volumio[31889]: info: Applying required configuration parameters for plugin rad357pl May 10 14:02:33 volumio volumio[31889]: info: [1715342553698] [rad357pl] API delay: 5 May 10 14:02:33 volumio volumio[31889]: info: Loading plugin "radio_paradise"... May 10 14:02:33 volumio go-librespot[32000]: time="2024-05-10T14:02:33+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" May 10 14:02:33 volumio volumio[31889]: Starting albumart workers May 10 14:02:34 volumio volumio[31889]: info: Applying required configuration parameters for plugin radio_paradise May 10 14:02:34 volumio volumio[31889]: info: [1715342554127] [RadioParadise] API delay: 5 May 10 14:02:34 volumio volumio[31889]: info: Loading plugin "backup_restore"... May 10 14:02:34 volumio go-librespot[32000]: time="2024-05-10T14:02:34+02:00" level=debug msg="completed keyexchange" May 10 14:02:34 volumio volumio[31889]: Starting albumart workers May 10 14:02:34 volumio volumio[31889]: Starting albumart workers May 10 14:02:34 volumio volumio[31889]: info: Applying required configuration parameters for plugin backup_restore May 10 14:02:34 volumio volumio[31889]: info: Loading plugin "music_services_shield"... May 10 14:02:34 volumio go-librespot[32000]: time="2024-05-10T14:02:34+02:00" level=debug msg="completed challenge" May 10 14:02:34 volumio go-librespot[32000]: time="2024-05-10T14:02:34+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 10 14:02:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 10 14:02:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 10 14:02:35 volumio volumio[31889]: info: Applying required configuration parameters for plugin music_services_shield May 10 14:02:35 volumio volumio[31889]: info: Loading i18n strings for locale pl May 10 14:02:35 volumio volumio[31889]: Updating browse sources language May 10 14:02:35 volumio volumio[31889]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 10 14:02:35 volumio volumio[31889]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 10 14:02:35 volumio volumio[31889]: info: CoreCommandRouter::initPlayerControls May 10 14:02:35 volumio volumio[31889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 10 14:02:35 volumio volumio[31889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 10 14:02:35 volumio volumio[31889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 10 14:02:35 volumio volumio[31889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 10 14:02:35 volumio volumio[31889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 10 14:02:35 volumio volumio[31889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 10 14:02:35 volumio volumio[31889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 10 14:02:35 volumio volumio[31889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 10 14:02:35 volumio volumio[31889]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 10 14:02:35 volumio volumio[31889]: Express server listening on port 3000 May 10 14:02:35 volumio volumio[31889]: [Metrics] WebUI: 13s 915.78ms May 10 14:02:35 volumio volumio[31889]: info: CoreStateMachine::resetVolumioState May 10 14:02:35 volumio volumio[31889]: info: CoreStateMachine::getcurrentVolume May 10 14:02:35 volumio volumio[31889]: info: CoreCommandRouter::volumioRetrievevolume May 10 14:02:35 volumio volumio[31889]: info: CoreStateMachine::pushState May 10 14:02:35 volumio volumio[31889]: info: CorePlayQueue::getTrack 0 May 10 14:02:35 volumio volumio[31889]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 10 14:02:35 volumio volumio[31889]: info: CoreCommandRouter::volumioPushState May 10 14:02:35 volumio volumio[31889]: info: Cannot mount NAS Muzyka_NAS at system boot, trial number 2 ,retrying in 5 seconds May 10 14:02:35 volumio sudo[32035]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 10 14:02:35 volumio sudo[32035]: pam_unix(sudo:session): session opened for user root by (uid=0) May 10 14:02:35 volumio sudo[32035]: pam_unix(sudo:session): session closed for user root May 10 14:02:36 volumio sudo[32037]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 10 14:02:36 volumio sudo[32037]: pam_unix(sudo:session): session opened for user root by (uid=0) May 10 14:02:36 volumio sudo[32037]: pam_unix(sudo:session): session closed for user root May 10 14:02:36 volumio volumio[31889]: verbose: New Socket.io Connection to 192.168.50.10 from 192.168.50.68 UA: okhttp/4.9.2 Total Clients: 1 May 10 14:02:36 volumio volumio[31889]: verbose: New Socket.io Connection to 192.168.50.10 from 192.168.50.68 UA: okhttp/4.9.2 Total Clients: 2 May 10 14:02:36 volumio volumio[31889]: verbose: New Socket.io Connection to 192.168.50.10 from 192.168.50.68 UA: okhttp/4.9.2 Total Clients: 3 May 10 14:02:36 volumio volumio[31889]: verbose: New Socket.io Connection to 192.168.50.10 from 192.168.50.68 UA: okhttp/4.9.2 Total Clients: 4 May 10 14:02:36 volumio volumio[31889]: verbose: New Socket.io Connection to 192.168.50.10 from 192.168.50.68 UA: okhttp/4.9.2 Total Clients: 5 May 10 14:02:36 volumio volumio[31889]: verbose: New Socket.io Connection to 192.168.50.10 from 192.168.50.68 UA: okhttp/4.9.2 Total Clients: 6 May 10 14:02:36 volumio volumio[31889]: verbose: New Socket.io Connection to 192.168.50.10 from 192.168.50.68 UA: okhttp/4.9.2 Total Clients: 7 May 10 14:02:36 volumio volumio[31889]: verbose: New Socket.io Connection to 192.168.50.10 from 192.168.50.68 UA: okhttp/4.9.2 Total Clients: 8 May 10 14:02:36 volumio volumio[31889]: verbose: New Socket.io Connection to 192.168.50.10 from 192.168.50.68 UA: okhttp/4.9.2 Total Clients: 9 May 10 14:02:36 volumio volumio[31889]: verbose: New Socket.io Connection to 192.168.50.10 from 192.168.50.68 UA: okhttp/4.9.2 Total Clients: 10 May 10 14:02:36 volumio volumio[31889]: verbose: New Socket.io Connection to 192.168.50.10 from 192.168.50.68 UA: okhttp/4.9.2 Total Clients: 11 May 10 14:02:36 volumio volumio[31889]: info: Reloading queue from file May 10 14:02:36 volumio volumio[31889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 10 14:02:36 volumio volumio[31889]: verbose: New Socket.io Connection to 192.168.50.10 from 192.168.50.68 UA: okhttp/4.9.2 Total Clients: 12 May 10 14:02:36 volumio volumio[31889]: info: Setting Device type: Raspberry PI May 10 14:02:36 volumio volumio[31889]: info: CoreStateMachine::setRepeat null single undefined May 10 14:02:36 volumio volumio[31889]: info: CoreStateMachine::pushState May 10 14:02:36 volumio volumio[31889]: info: CorePlayQueue::getTrack 0 May 10 14:02:36 volumio volumio[31889]: info: CoreCommandRouter::volumioPushState May 10 14:02:36 volumio volumio[31889]: info: CoreStateMachine::setRandom null May 10 14:02:36 volumio volumio[31889]: info: CoreStateMachine::pushState May 10 14:02:36 volumio volumio[31889]: info: CorePlayQueue::getTrack 0 May 10 14:02:36 volumio volumio[31889]: info: CoreCommandRouter::volumioPushState May 10 14:02:36 volumio volumio[31889]: info: CoreCommandRouter::volumioGetState May 10 14:02:36 volumio volumio[31889]: info: CorePlayQueue::getTrack 0 May 10 14:02:36 volumio sudo[32046]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service May 10 14:02:36 volumio volumio[31889]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 10 14:02:36 volumio sudo[32046]: pam_unix(sudo:session): session opened for user root by (uid=0) May 10 14:02:36 volumio volumio[31889]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 10 14:02:36 volumio sudo[32046]: pam_unix(sudo:session): session closed for user root May 10 14:02:36 volumio volumio[31889]: info: Upmpdcli Daemon Started May 10 14:02:36 volumio volumio[31889]: info: Discovery: adding 05d85d49-20e7-474d-a010-45a8c2bbba8d May 10 14:02:36 volumio volumio[31889]: info: Discovery: Found device Volumio May 10 14:02:36 volumio volumio[31889]: info: CoreCommandRouter::volumioGetState May 10 14:02:36 volumio volumio[31889]: info: CorePlayQueue::getTrack 0 May 10 14:02:37 volumio volumio-remote-updater[470]: [2024-05-10 14:02:37] [connect] Successful connection May 10 14:02:37 volumio volumio-remote-updater[470]: [2024-05-10 14:02:37] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1715342557 101 May 10 14:02:37 volumio volumio[31889]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Total Clients: 13 May 10 14:02:37 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 10 14:02:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14131. May 10 14:02:37 volumio systemd[1]: Stopped go-librespot Daemon. May 10 14:02:37 volumio systemd[1]: Started go-librespot Daemon. May 10 14:02:37 volumio go-librespot[32048]: Librespot-go daemon starting... May 10 14:02:37 volumio go-librespot[32048]: time="2024-05-10T14:02:37+02:00" level=info msg="generated new device id: e35818f443f538de8eebc75e3754a0845a627339" May 10 14:02:37 volumio go-librespot[32048]: time="2024-05-10T14:02:37+02:00" level=debug msg="stored credentials found for cspxgxr4w2nqbsxykzro5zm83" May 10 14:02:38 volumio go-librespot[32048]: time="2024-05-10T14:02:38+02:00" level=debug msg="obtained new client token: AABKq0HFd9KaSoDzosSoiDnfHgiaZ9VmNSTwHXCPXKbvMkXhNMCci0gYQUXKCtAjXHSmwuu1w1+4APFVfs4G3kZujLBokQw5MrOAVqvqavtYqL6a7Al+01R4t9IKCKyFuwo2FQNrAPifBwsSMym4Tx4AcezEz8tkDoFeqSeAjTjSFbJPRlalRdcVONARyvl9A5EO5XVbV/dmEdwuRSfGCuWakWgURr3UKQgbgKkZFhYAHYT+P6d5TO3eQKtzNA==" May 10 14:02:38 volumio go-librespot[32048]: time="2024-05-10T14:02:38+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" May 10 14:02:38 volumio go-librespot[32048]: time="2024-05-10T14:02:38+02:00" level=debug msg="completed keyexchange" May 10 14:02:38 volumio volumio[31889]: verbose: New Socket.io Connection to 192.168.50.10 from 192.168.50.68 UA: okhttp/4.9.2 Total Clients: 14 May 10 14:02:38 volumio go-librespot[32048]: time="2024-05-10T14:02:38+02:00" level=debug msg="completed challenge" May 10 14:02:38 volumio volumio[31889]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 10 14:02:39 volumio volumio[31889]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 10 14:02:39 volumio volumio[31889]: info: CoreCommandRouter::volumioGetVisibleSources May 10 14:02:39 volumio volumio[31889]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 10 14:02:39 volumio volumio[31889]: info: CoreCommandRouter::volumioGetState May 10 14:02:39 volumio volumio[31889]: info: CorePlayQueue::getTrack 0 May 10 14:02:39 volumio volumio[31889]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 10 14:02:39 volumio volumio[31889]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 10 14:02:39 volumio go-librespot[32048]: time="2024-05-10T14:02:39+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" May 10 14:02:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 10 14:02:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 10 14:02:39 volumio volumio[31889]: info: Received Get System Info May 10 14:02:39 volumio volumio[31889]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 10 14:02:39 volumio volumio[31889]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 10 14:02:39 volumio volumio[31889]: info: Discovery: Getting this device information May 10 14:02:39 volumio volumio[31889]: info: CoreCommandRouter::volumioGetState May 10 14:02:39 volumio volumio[31889]: info: CorePlayQueue::getTrack 0 May 10 14:02:39 volumio volumio[31889]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 10 14:02:39 volumio volumio[31889]: info: CoreCommandRouter::volumioGetState May 10 14:02:39 volumio volumio[31889]: info: CorePlayQueue::getTrack 0 May 10 14:02:39 volumio volumio[31889]: info: Listing playlists May 10 14:02:39 volumio volumio[31889]: info: CoreCommandRouter::volumioGetQueue May 10 14:02:39 volumio volumio[31889]: info: CoreStateMachine::getQueue May 10 14:02:39 volumio volumio[31889]: info: CorePlayQueue::getQueue May 10 14:02:40 volumio volumio[31889]: info: Cannot mount NAS Muzyka_NAS at system boot, trial number 3 ,retrying in 5 seconds May 10 14:02:42 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 10 14:02:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14132. May 10 14:02:42 volumio systemd[1]: Stopped go-librespot Daemon. May 10 14:02:42 volumio systemd[1]: Started go-librespot Daemon. May 10 14:02:42 volumio go-librespot[32056]: Librespot-go daemon starting... May 10 14:02:42 volumio go-librespot[32056]: time="2024-05-10T14:02:42+02:00" level=info msg="generated new device id: cb2d13b695d78d02135e66d74564317bc4145fbe" May 10 14:02:42 volumio go-librespot[32056]: time="2024-05-10T14:02:42+02:00" level=debug msg="stored credentials found for cspxgxr4w2nqbsxykzro5zm83" May 10 14:02:42 volumio go-librespot[32056]: time="2024-05-10T14:02:42+02:00" level=debug msg="obtained new client token: AABgRAPiIaNKWHtA10JCpa5pZI/0u7S3zZrCk7MT7o1BaKLqTY+CbdfUlTJGNLkCrGKVcWHoh1dyY2sYUkuvrQkTVlJlcOSdwQwxd2MwW83N9dKspF9ZXH8wa9ZL/dUCXkOGT1VHfjoUtIkn/RmKgKoLFfDMERxrkgMHr7uRm1Op7TaLf2/acPU2A+E895lLfZ9LXOSTwgJFIP1vU+taKA0SIXWsfRS3N4orHm4oEf+0Khudx1ntdcBiTqHL+Y16" May 10 14:02:42 volumio go-librespot[32056]: time="2024-05-10T14:02:42+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" May 10 14:02:43 volumio volumio[31889]: info: Preload queue cleared May 10 14:02:43 volumio volumio[31889]: info: CoreCommandRouter::volumioReplaceandPlayItems May 10 14:02:43 volumio volumio[31889]: info: CoreStateMachine::ClearQueue May 10 14:02:43 volumio volumio[31889]: info: CoreStateMachine::stop May 10 14:02:43 volumio volumio[31889]: info: CoreStateMachine::setConsumeUpdateService undefined May 10 14:02:43 volumio volumio[31889]: info: CorePlayQueue::clearPlayQueue May 10 14:02:43 volumio volumio[31889]: info: CorePlayQueue::saveQueue May 10 14:02:43 volumio volumio[31889]: info: CoreCommandRouter::volumioPushQueue May 10 14:02:43 volumio volumio[31889]: info: CoreStateMachine::addQueueItems May 10 14:02:43 volumio volumio[31889]: info: CorePlayQueue::addQueueItems May 10 14:02:43 volumio volumio[31889]: info: Preload queue cleared May 10 14:02:43 volumio volumio[31889]: info: Adding Item to queue: music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-01The Expert.flac May 10 14:02:43 volumio volumio[31889]: info: Exploding uri music-library/NAS/Muzyka_NAS/Yello/YELLOTouch Yello-01The Expert.flac in service mpd May 10 14:02:43 volumio volumio[31889]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 10 14:02:43 volumio volumio[31889]: TypeError: Cannot read property 'then' of undefined May 10 14:02:43 volumio volumio[31889]: at ControllerMpd.scanFolder (/volumio/app/plugins/music_service/mpd/index.js:2527:19) May 10 14:02:43 volumio volumio[31889]: at ControllerMpd.explodeUri (/volumio/app/plugins/music_service/mpd/index.js:2325:21) May 10 14:02:43 volumio volumio[31889]: at CoreCommandRouter.explodeUriFromService (/volumio/app/index.js:1359:16) May 10 14:02:43 volumio volumio[31889]: at CorePlayQueue.explodeUriFromCache (/volumio/app/playqueue.js:123:24) May 10 14:02:43 volumio volumio[31889]: at CorePlayQueue.explodeUri (/volumio/app/playqueue.js:181:19) May 10 14:02:43 volumio volumio[31889]: at CorePlayQueue.addQueueItems (/volumio/app/playqueue.js:223:30) May 10 14:02:43 volumio volumio[31889]: at CoreStateMachine.addQueueItems (/volumio/app/statemachine.js:247:25) May 10 14:02:43 volumio volumio[31889]: at CoreCommandRouter.replaceAndPlay (/volumio/app/index.js:501:23) May 10 14:02:43 volumio volumio[31889]: at CoreCommandRouter.playItemsList (/volumio/app/index.js:477:17) May 10 14:02:43 volumio volumio[31889]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:118:33) May 10 14:02:43 volumio volumio[31889]: at Socket.emit (events.js:315:20) May 10 14:02:43 volumio volumio[31889]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 May 10 14:02:43 volumio volumio[31889]: at processTicksAndRejections (internal/process/task_queues.js:75:11) May 10 14:02:43 volumio volumio[31889]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 10 14:02:43 volumio go-librespot[32056]: time="2024-05-10T14:02:43+02:00" level=debug msg="completed keyexchange" May 10 14:02:43 volumio sudo[32072]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-05-10 14:01 May 10 14:02:43 volumio sudo[32072]: pam_unix(sudo:session): session opened for user root by (uid=0) May 10 14:02:43 volumio go-librespot[32056]: time="2024-05-10T14:02:43+02:00" level=debug msg="completed challenge" PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="7f9f1bf001add7a8b19a4516e3c74ef598b2730d" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="512433c3e91cdaed7ecd2808b21adeffc2137d7f" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 21 Feb 2024 09:37:22 PM CET" VOLUMIO_VERSION="3.631" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fdd9dd1169c06c1ad0a30ddd24c91b6b"