-- Logs begin at Sat 2025-03-01 19:15:25 CST, end at Sat 2025-03-01 19:30:06 CST. -- Mar 01 19:29:06 dac.x2-nvme wpa_supplicant[1161]: wlan0: Failed to initiate sched scan Mar 01 19:29:13 dac.x2-nvme go-librespot[5312]: time="2025-03-01T19:29:13+08:00" level=debug msg="obtained new client token: AADhICAdDX6O8BpP04/yfad1b09B/GPnvElBYHT4Pxi9vG6csCVyZ9J8HuNWN1beOSMGxJAW9fAhZUgpdcTYis6LhagMgywppqAeJR/n9D0rSAvAdFNqQMWEgbeZrdY9jxqIkWNsyI9pdDYNK29BbJbQZ/yRG9L89Lzti8NF9iYWGfNgSAh28apJwCWO3ulhIQpmEcglSq4sgal/AybPbLvFQm2WUCYkWpE9lYZZva4l8hcAl8nCQ5E=" Mar 01 19:29:13 dac.x2-nvme go-librespot[5312]: time="2025-03-01T19:29:13+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 01 19:29:13 dac.x2-nvme go-librespot[5312]: time="2025-03-01T19:29:13+08:00" level=debug msg="completed keyexchange" Mar 01 19:29:13 dac.x2-nvme go-librespot[5312]: time="2025-03-01T19:29:13+08:00" level=debug msg="completed challenge" Mar 01 19:29:13 dac.x2-nvme go-librespot[5312]: time="2025-03-01T19:29:13+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Mar 01 19:29:13 dac.x2-nvme systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 19:29:13 dac.x2-nvme systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 19:29:13 dac.x2-nvme volumio[1345]: (node:1345) UnhandledPromiseRejectionWarning: Error: socket hang up Mar 01 19:29:13 dac.x2-nvme volumio[1345]: at connResetException (internal/errors.js:607:14) Mar 01 19:29:13 dac.x2-nvme volumio[1345]: at Socket.socketOnEnd (_http_client.js:493:23) Mar 01 19:29:13 dac.x2-nvme volumio[1345]: at Socket.emit (events.js:327:22) Mar 01 19:29:13 dac.x2-nvme volumio[1345]: at endReadableNT (internal/streams/readable.js:1327:12) Mar 01 19:29:13 dac.x2-nvme volumio[1345]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Mar 01 19:29:13 dac.x2-nvme volumio[1345]: (node:1345) 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: 46) Mar 01 19:29:13 dac.x2-nvme volumio[1345]: info: Connection to go-librespot Websocket closed Mar 01 19:29:15 dac.x2-nvme wpa_supplicant[1161]: wlan0: Failed to initiate sched scan Mar 01 19:29:15 dac.x2-nvme volumio[1345]: error: MyVolumio got a network error: A network error (such as timeout, interrupted connection or unreachable host) has occurred. Mar 01 19:29:15 dac.x2-nvme volumio[1345]: info: Retrying Login Due to Network Error Mar 01 19:29:16 dac.x2-nvme volumio[1345]: info: Initializing connection to go-librespot Websocket Mar 01 19:29:16 dac.x2-nvme volumio[1345]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 19:29:16 dac.x2-nvme systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 19:29:16 dac.x2-nvme systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 151. Mar 01 19:29:16 dac.x2-nvme systemd[1]: Stopped go-librespot Daemon. Mar 01 19:29:16 dac.x2-nvme systemd[1]: Started go-librespot Daemon. Mar 01 19:29:16 dac.x2-nvme go-librespot[5369]: go-librespot daemon starting... Mar 01 19:29:16 dac.x2-nvme go-librespot[5369]: time="2025-03-01T19:29:16+08:00" level=info msg="running go-librespot 0.2.0" Mar 01 19:29:16 dac.x2-nvme go-librespot[5369]: time="2025-03-01T19:29:16+08:00" level=debug msg="app state loaded" Mar 01 19:29:16 dac.x2-nvme go-librespot[5369]: time="2025-03-01T19:29:16+08:00" level=debug msg="stored credentials not found" Mar 01 19:29:16 dac.x2-nvme go-librespot[5369]: time="2025-03-01T19:29:16+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 01 19:29:17 dac.x2-nvme go-librespot[5369]: time="2025-03-01T19:29:17+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 01 19:29:17 dac.x2-nvme go-librespot[5369]: time="2025-03-01T19:29:17+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Mar 01 19:29:17 dac.x2-nvme go-librespot[5369]: time="2025-03-01T19:29:17+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Mar 01 19:29:17 dac.x2-nvme go-librespot[5369]: time="2025-03-01T19:29:17+08:00" level=info msg="zeroconf server listening on port 34365" Mar 01 19:29:18 dac.x2-nvme go-librespot[5369]: time="2025-03-01T19:29:18+08:00" level=debug msg="obtained new client token: AABWmic2o57+5K97+oXq2xNMJ7qS3WffDIqj+WgtGOslPZhj/NHhrw+N9qDD9/MBzMWlVgFKi/KLytzVt3Y1ZJlHRmj3yEivHzJ5nYyXxcNoUY0nNKybpcW63XB/a1Zg1zTXRh6902bgrcykIbRoSHA5PsvMoTPEQWaDp8C1PhsdwQufy5LXXGysA/52sGpASms/6qjvyICHzMsDRGMaXoKnkpg2JNNKGTOX7UKFtMpOO7sLADnmA8s=" Mar 01 19:29:18 dac.x2-nvme go-librespot[5369]: time="2025-03-01T19:29:18+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 01 19:29:18 dac.x2-nvme go-librespot[5369]: time="2025-03-01T19:29:18+08:00" level=debug msg="completed keyexchange" Mar 01 19:29:18 dac.x2-nvme go-librespot[5369]: time="2025-03-01T19:29:18+08:00" level=debug msg="completed challenge" Mar 01 19:29:18 dac.x2-nvme go-librespot[5369]: time="2025-03-01T19:29:18+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Mar 01 19:29:18 dac.x2-nvme systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 19:29:18 dac.x2-nvme systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 19:29:19 dac.x2-nvme volumio[1345]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 01 19:29:19 dac.x2-nvme volumio[1345]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 01 19:29:19 dac.x2-nvme volumio[1345]: info: Discovery: Getting this device information Mar 01 19:29:19 dac.x2-nvme volumio[1345]: info: CoreCommandRouter::volumioGetState Mar 01 19:29:19 dac.x2-nvme volumio[1345]: info: CorePlayQueue::getTrack 0 Mar 01 19:29:19 dac.x2-nvme volumio[1345]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 01 19:29:19 dac.x2-nvme volumio[1345]: info: Initializing connection to go-librespot Websocket Mar 01 19:29:19 dac.x2-nvme volumio[1345]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 19:29:21 dac.x2-nvme systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 19:29:21 dac.x2-nvme systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 152. Mar 01 19:29:21 dac.x2-nvme systemd[1]: Stopped go-librespot Daemon. Mar 01 19:29:21 dac.x2-nvme systemd[1]: Started go-librespot Daemon. Mar 01 19:29:21 dac.x2-nvme go-librespot[5380]: go-librespot daemon starting... Mar 01 19:29:21 dac.x2-nvme go-librespot[5380]: time="2025-03-01T19:29:21+08:00" level=info msg="running go-librespot 0.2.0" Mar 01 19:29:21 dac.x2-nvme go-librespot[5380]: time="2025-03-01T19:29:21+08:00" level=debug msg="app state loaded" Mar 01 19:29:21 dac.x2-nvme go-librespot[5380]: time="2025-03-01T19:29:21+08:00" level=debug msg="stored credentials not found" Mar 01 19:29:21 dac.x2-nvme go-librespot[5380]: time="2025-03-01T19:29:21+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 01 19:29:22 dac.x2-nvme go-librespot[5380]: time="2025-03-01T19:29:22+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 01 19:29:22 dac.x2-nvme go-librespot[5380]: time="2025-03-01T19:29:22+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Mar 01 19:29:22 dac.x2-nvme go-librespot[5380]: time="2025-03-01T19:29:22+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Mar 01 19:29:22 dac.x2-nvme go-librespot[5380]: time="2025-03-01T19:29:22+08:00" level=info msg="zeroconf server listening on port 44799" Mar 01 19:29:22 dac.x2-nvme volumio[1345]: info: Initializing connection to go-librespot Websocket Mar 01 19:29:22 dac.x2-nvme go-librespot[5380]: time="2025-03-01T19:29:22+08:00" level=debug msg="new websocket client" Mar 01 19:29:22 dac.x2-nvme volumio[1345]: info: Connection to go-librespot Websocket established Mar 01 19:29:23 dac.x2-nvme go-librespot[5380]: time="2025-03-01T19:29:23+08:00" level=debug msg="obtained new client token: AABwD4TufE51ehstDxoejn+EwFIZSGFoBfnJy+bxxA5j1QHTEEBxy3IMK1GBmfp3l9C4aUSt0L1KXt4kb5cGMq9sEJSjfwix6l+J6R+StIwOlOx/a3KkpFJUQPD+p6pFttrXnMcXNkbcNVqcp+s3ryP3/7Hyn3qGM833rxx+tD/p5hykes83YQiT5OnwBMY1yotIo4LKk5SHYB1BiNsdGm0bNvU6495x6DHzWmKzmp/1fFCpLmxR" Mar 01 19:29:23 dac.x2-nvme go-librespot[5380]: time="2025-03-01T19:29:23+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 01 19:29:23 dac.x2-nvme go-librespot[5380]: time="2025-03-01T19:29:23+08:00" level=debug msg="completed keyexchange" Mar 01 19:29:23 dac.x2-nvme go-librespot[5380]: time="2025-03-01T19:29:23+08:00" level=debug msg="completed challenge" Mar 01 19:29:23 dac.x2-nvme go-librespot[5380]: time="2025-03-01T19:29:23+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Mar 01 19:29:23 dac.x2-nvme volumio[1345]: info: Connection to go-librespot Websocket closed Mar 01 19:29:23 dac.x2-nvme systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 19:29:23 dac.x2-nvme systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 19:29:23 dac.x2-nvme wpa_supplicant[1161]: wlan0: Failed to initiate sched scan Mar 01 19:29:25 dac.x2-nvme volumio[1345]: info: MyVolumio login type: Token Mar 01 19:29:25 dac.x2-nvme volumio[1345]: info: Getting Spotify volume Mar 01 19:29:25 dac.x2-nvme volumio[1345]: (node:1345) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 19:29:25 dac.x2-nvme volumio[1345]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 01 19:29:25 dac.x2-nvme volumio[1345]: (node:1345) 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: 47) Mar 01 19:29:25 dac.x2-nvme volumio[1345]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Mar 01 19:29:25 dac.x2-nvme volumio[1345]: info: CoreCommandRouter::volumioGetState Mar 01 19:29:25 dac.x2-nvme volumio[1345]: info: CorePlayQueue::getTrack 0 Mar 01 19:29:26 dac.x2-nvme volumio[1345]: info: Initializing connection to go-librespot Websocket Mar 01 19:29:26 dac.x2-nvme volumio[1345]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 19:29:26 dac.x2-nvme systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 19:29:26 dac.x2-nvme systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 153. Mar 01 19:29:26 dac.x2-nvme systemd[1]: Stopped go-librespot Daemon. Mar 01 19:29:26 dac.x2-nvme systemd[1]: Started go-librespot Daemon. Mar 01 19:29:26 dac.x2-nvme go-librespot[5402]: go-librespot daemon starting... Mar 01 19:29:26 dac.x2-nvme go-librespot[5402]: time="2025-03-01T19:29:26+08:00" level=info msg="running go-librespot 0.2.0" Mar 01 19:29:26 dac.x2-nvme go-librespot[5402]: time="2025-03-01T19:29:26+08:00" level=debug msg="app state loaded" Mar 01 19:29:26 dac.x2-nvme go-librespot[5402]: time="2025-03-01T19:29:26+08:00" level=debug msg="stored credentials not found" Mar 01 19:29:26 dac.x2-nvme go-librespot[5402]: time="2025-03-01T19:29:26+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 01 19:29:26 dac.x2-nvme go-librespot[5402]: time="2025-03-01T19:29:26+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 01 19:29:26 dac.x2-nvme go-librespot[5402]: time="2025-03-01T19:29:26+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Mar 01 19:29:26 dac.x2-nvme go-librespot[5402]: time="2025-03-01T19:29:26+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Mar 01 19:29:27 dac.x2-nvme go-librespot[5402]: time="2025-03-01T19:29:27+08:00" level=info msg="zeroconf server listening on port 33293" Mar 01 19:29:27 dac.x2-nvme go-librespot[5402]: time="2025-03-01T19:29:27+08:00" level=debug msg="obtained new client token: AAD6XW660HZzHhstTATlrUhvCSMABrUWp7pJrNUl/FAcc7t3T8aPraFK6ZZ66Bs//DpG8BGG22Fk1Mo1QJLVqDcAug/k+b5huijZBCCoiNzfWOBl60IgbRR2gWHmmIlXEhKHnwqeIlS2k3+/is2vPR75+G4CaJdOAutd7Bhk1WMZNQ/4Z+Tl58fIF+MJgn+yc3pEgF6xv4uS8WjWgOupbENlhW3cINukY1GOOYxPTz2OkcLViBgL59g=" Mar 01 19:29:27 dac.x2-nvme go-librespot[5402]: time="2025-03-01T19:29:27+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 01 19:29:27 dac.x2-nvme go-librespot[5402]: time="2025-03-01T19:29:27+08:00" level=debug msg="completed keyexchange" Mar 01 19:29:27 dac.x2-nvme go-librespot[5402]: time="2025-03-01T19:29:27+08:00" level=debug msg="completed challenge" Mar 01 19:29:27 dac.x2-nvme go-librespot[5402]: time="2025-03-01T19:29:27+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Mar 01 19:29:27 dac.x2-nvme systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 19:29:27 dac.x2-nvme systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 19:29:28 dac.x2-nvme volumiologrotate[796]: ls: cannot access '/var/log/samba/log.wb-DAC.X2': No such file or directory Mar 01 19:29:28 dac.x2-nvme volumiologrotate[796]: ls: cannot access 'NVME': No such file or directory Mar 01 19:29:29 dac.x2-nvme volumio[1345]: info: Initializing connection to go-librespot Websocket Mar 01 19:29:29 dac.x2-nvme volumio[1345]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 19:29:30 dac.x2-nvme systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 19:29:30 dac.x2-nvme systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 154. Mar 01 19:29:30 dac.x2-nvme systemd[1]: Stopped go-librespot Daemon. Mar 01 19:29:30 dac.x2-nvme systemd[1]: Started go-librespot Daemon. Mar 01 19:29:30 dac.x2-nvme go-librespot[5458]: go-librespot daemon starting... Mar 01 19:29:30 dac.x2-nvme go-librespot[5458]: time="2025-03-01T19:29:30+08:00" level=info msg="running go-librespot 0.2.0" Mar 01 19:29:30 dac.x2-nvme go-librespot[5458]: time="2025-03-01T19:29:30+08:00" level=debug msg="app state loaded" Mar 01 19:29:30 dac.x2-nvme go-librespot[5458]: time="2025-03-01T19:29:30+08:00" level=debug msg="stored credentials not found" Mar 01 19:29:30 dac.x2-nvme go-librespot[5458]: time="2025-03-01T19:29:30+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 01 19:29:31 dac.x2-nvme wpa_supplicant[1161]: wlan0: Failed to initiate sched scan Mar 01 19:29:31 dac.x2-nvme go-librespot[5458]: time="2025-03-01T19:29:31+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 01 19:29:31 dac.x2-nvme go-librespot[5458]: time="2025-03-01T19:29:31+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Mar 01 19:29:31 dac.x2-nvme go-librespot[5458]: time="2025-03-01T19:29:31+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Mar 01 19:29:31 dac.x2-nvme go-librespot[5458]: time="2025-03-01T19:29:31+08:00" level=info msg="zeroconf server listening on port 38063" Mar 01 19:29:32 dac.x2-nvme volumio[1345]: info: Initializing connection to go-librespot Websocket Mar 01 19:29:32 dac.x2-nvme go-librespot[5458]: time="2025-03-01T19:29:32+08:00" level=debug msg="new websocket client" Mar 01 19:29:32 dac.x2-nvme volumio[1345]: info: Connection to go-librespot Websocket established Mar 01 19:29:32 dac.x2-nvme go-librespot[5458]: time="2025-03-01T19:29:32+08:00" level=debug msg="obtained new client token: AAANgr4N5LFnHGV0BKeTKtbx67tQVH7Yy3PKWtOZ0ae2OwLS1A6eYH6diKSztoQNKqwi+DyRqV5JDAHOqCh2392mmK6ITsHJOmL7RV0wBpOSSuv7qZd1/HjiaQfLKKyYSIH7VNaShSW8qUrkCVldHspLGzQJ5ATwGVSzAEjfSb1t1CtsFpb22OjS/4eyBUFmG7/rllGFYsiWlxkjlBTMqjSzyAOWpqzvKEANi8lErogQZDpaFXv5AKE=" Mar 01 19:29:32 dac.x2-nvme go-librespot[5458]: time="2025-03-01T19:29:32+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 01 19:29:32 dac.x2-nvme go-librespot[5458]: time="2025-03-01T19:29:32+08:00" level=debug msg="completed keyexchange" Mar 01 19:29:32 dac.x2-nvme go-librespot[5458]: time="2025-03-01T19:29:32+08:00" level=debug msg="completed challenge" Mar 01 19:29:32 dac.x2-nvme go-librespot[5458]: time="2025-03-01T19:29:32+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Mar 01 19:29:32 dac.x2-nvme volumio[1345]: info: Connection to go-librespot Websocket closed Mar 01 19:29:32 dac.x2-nvme systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 19:29:32 dac.x2-nvme systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 19:29:35 dac.x2-nvme volumio[1345]: info: Getting Spotify volume Mar 01 19:29:35 dac.x2-nvme volumio[1345]: (node:1345) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 19:29:35 dac.x2-nvme volumio[1345]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 01 19:29:35 dac.x2-nvme volumio[1345]: (node:1345) 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: 48) Mar 01 19:29:35 dac.x2-nvme volumio[1345]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Mar 01 19:29:35 dac.x2-nvme volumio[1345]: info: CoreCommandRouter::volumioGetState Mar 01 19:29:35 dac.x2-nvme volumio[1345]: info: CorePlayQueue::getTrack 0 Mar 01 19:29:35 dac.x2-nvme volumio[1345]: info: Initializing connection to go-librespot Websocket Mar 01 19:29:35 dac.x2-nvme volumio[1345]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 19:29:35 dac.x2-nvme systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 19:29:35 dac.x2-nvme systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 155. Mar 01 19:29:35 dac.x2-nvme systemd[1]: Stopped go-librespot Daemon. Mar 01 19:29:35 dac.x2-nvme systemd[1]: Started go-librespot Daemon. Mar 01 19:29:35 dac.x2-nvme go-librespot[5480]: go-librespot daemon starting... Mar 01 19:29:35 dac.x2-nvme go-librespot[5480]: time="2025-03-01T19:29:35+08:00" level=info msg="running go-librespot 0.2.0" Mar 01 19:29:35 dac.x2-nvme go-librespot[5480]: time="2025-03-01T19:29:35+08:00" level=debug msg="app state loaded" Mar 01 19:29:35 dac.x2-nvme go-librespot[5480]: time="2025-03-01T19:29:35+08:00" level=debug msg="stored credentials not found" Mar 01 19:29:35 dac.x2-nvme go-librespot[5480]: time="2025-03-01T19:29:35+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 01 19:29:36 dac.x2-nvme go-librespot[5480]: time="2025-03-01T19:29:36+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 01 19:29:36 dac.x2-nvme go-librespot[5480]: time="2025-03-01T19:29:36+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Mar 01 19:29:36 dac.x2-nvme go-librespot[5480]: time="2025-03-01T19:29:36+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Mar 01 19:29:36 dac.x2-nvme go-librespot[5480]: time="2025-03-01T19:29:36+08:00" level=info msg="zeroconf server listening on port 33941" Mar 01 19:29:37 dac.x2-nvme go-librespot[5480]: time="2025-03-01T19:29:37+08:00" level=debug msg="obtained new client token: AAALHCWnAInOC41bFVdXGYmKbTk0oC7R+FZn6voLmkKnnNqSrnHr8/crfcOIvQwz2b8szMDCf8AqTPqsO7n8xpPnoxFQVnmOw9VYkT8U7ob+0peFPcDUZcrg9w7dUsgfqCub76YroQVi82grreMlAxBzR+CLHLZoqJ3FjWdPy+GuR7WjkuxreCvWPAdBKue3tlY4DV0siu1AStBalhhEj5xlBt4cm0X59JfjVpxkBhVRhagbx0xd" Mar 01 19:29:37 dac.x2-nvme go-librespot[5480]: time="2025-03-01T19:29:37+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 01 19:29:37 dac.x2-nvme go-librespot[5480]: time="2025-03-01T19:29:37+08:00" level=debug msg="completed keyexchange" Mar 01 19:29:37 dac.x2-nvme go-librespot[5480]: time="2025-03-01T19:29:37+08:00" level=debug msg="completed challenge" Mar 01 19:29:37 dac.x2-nvme go-librespot[5480]: time="2025-03-01T19:29:37+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Mar 01 19:29:37 dac.x2-nvme systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 19:29:37 dac.x2-nvme systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 19:29:38 dac.x2-nvme volumio[1345]: info: Initializing connection to go-librespot Websocket Mar 01 19:29:38 dac.x2-nvme volumio[1345]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 19:29:39 dac.x2-nvme wpa_supplicant[1161]: wlan0: Failed to initiate sched scan Mar 01 19:29:40 dac.x2-nvme systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 19:29:40 dac.x2-nvme systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 156. Mar 01 19:29:40 dac.x2-nvme systemd[1]: Stopped go-librespot Daemon. Mar 01 19:29:40 dac.x2-nvme systemd[1]: Started go-librespot Daemon. Mar 01 19:29:40 dac.x2-nvme go-librespot[5492]: go-librespot daemon starting... Mar 01 19:29:40 dac.x2-nvme go-librespot[5492]: time="2025-03-01T19:29:40+08:00" level=info msg="running go-librespot 0.2.0" Mar 01 19:29:40 dac.x2-nvme go-librespot[5492]: time="2025-03-01T19:29:40+08:00" level=debug msg="app state loaded" Mar 01 19:29:40 dac.x2-nvme go-librespot[5492]: time="2025-03-01T19:29:40+08:00" level=debug msg="stored credentials not found" Mar 01 19:29:40 dac.x2-nvme go-librespot[5492]: time="2025-03-01T19:29:40+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 01 19:29:41 dac.x2-nvme go-librespot[5492]: time="2025-03-01T19:29:41+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 01 19:29:41 dac.x2-nvme go-librespot[5492]: time="2025-03-01T19:29:41+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Mar 01 19:29:41 dac.x2-nvme go-librespot[5492]: time="2025-03-01T19:29:41+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Mar 01 19:29:41 dac.x2-nvme go-librespot[5492]: time="2025-03-01T19:29:41+08:00" level=info msg="zeroconf server listening on port 42511" Mar 01 19:29:41 dac.x2-nvme go-librespot[5492]: time="2025-03-01T19:29:41+08:00" level=debug msg="obtained new client token: AACXFLLGrENnCHeLLGzqLumjDUJTFnVCxux6N7kVxSzDWCGMYePjv3C5hejWSfc8cCRFk7InE1lbRMeosQkVYcMZR5WrZRCwggfsfXECSd6aTtZzWtcv881oMrXGriuUSoJ3UIS+q6zDB3IRmlMRCwqH9BhKH3KXOCZcbxBGlNQ4nAQaO1FMbHuW2T8n+OVzMzQcjuo5Xm9B7pRVjv08rGsTmYt1EPAGwZIAoNatsWIuzJ2hNlgkNYQ=" Mar 01 19:29:41 dac.x2-nvme volumio[1345]: info: Initializing connection to go-librespot Websocket Mar 01 19:29:41 dac.x2-nvme volumio[1345]: info: Connection to go-librespot Websocket established Mar 01 19:29:41 dac.x2-nvme go-librespot[5492]: time="2025-03-01T19:29:41+08:00" level=debug msg="new websocket client" Mar 01 19:29:41 dac.x2-nvme go-librespot[5492]: time="2025-03-01T19:29:41+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 01 19:29:41 dac.x2-nvme go-librespot[5492]: time="2025-03-01T19:29:41+08:00" level=debug msg="completed keyexchange" Mar 01 19:29:41 dac.x2-nvme go-librespot[5492]: time="2025-03-01T19:29:41+08:00" level=debug msg="completed challenge" Mar 01 19:29:41 dac.x2-nvme go-librespot[5492]: time="2025-03-01T19:29:41+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Mar 01 19:29:41 dac.x2-nvme systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 19:29:41 dac.x2-nvme systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 19:29:41 dac.x2-nvme volumio[1345]: info: Connection to go-librespot Websocket closed Mar 01 19:29:44 dac.x2-nvme volumio[1345]: info: Getting Spotify volume Mar 01 19:29:44 dac.x2-nvme volumio[1345]: (node:1345) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 19:29:44 dac.x2-nvme volumio[1345]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 01 19:29:44 dac.x2-nvme volumio[1345]: (node:1345) 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: 49) Mar 01 19:29:44 dac.x2-nvme volumio[1345]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Mar 01 19:29:44 dac.x2-nvme volumio[1345]: info: CoreCommandRouter::volumioGetState Mar 01 19:29:44 dac.x2-nvme volumio[1345]: info: CorePlayQueue::getTrack 0 Mar 01 19:29:44 dac.x2-nvme volumio[1345]: info: Initializing connection to go-librespot Websocket Mar 01 19:29:44 dac.x2-nvme volumio[1345]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 19:29:44 dac.x2-nvme systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 19:29:44 dac.x2-nvme systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 157. Mar 01 19:29:44 dac.x2-nvme systemd[1]: Stopped go-librespot Daemon. Mar 01 19:29:44 dac.x2-nvme systemd[1]: Started go-librespot Daemon. Mar 01 19:29:44 dac.x2-nvme go-librespot[5514]: go-librespot daemon starting... Mar 01 19:29:44 dac.x2-nvme go-librespot[5514]: time="2025-03-01T19:29:44+08:00" level=info msg="running go-librespot 0.2.0" Mar 01 19:29:44 dac.x2-nvme go-librespot[5514]: time="2025-03-01T19:29:44+08:00" level=debug msg="app state loaded" Mar 01 19:29:44 dac.x2-nvme go-librespot[5514]: time="2025-03-01T19:29:44+08:00" level=debug msg="stored credentials not found" Mar 01 19:29:44 dac.x2-nvme go-librespot[5514]: time="2025-03-01T19:29:44+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 01 19:29:45 dac.x2-nvme go-librespot[5514]: time="2025-03-01T19:29:45+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 01 19:29:45 dac.x2-nvme go-librespot[5514]: time="2025-03-01T19:29:45+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Mar 01 19:29:45 dac.x2-nvme go-librespot[5514]: time="2025-03-01T19:29:45+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Mar 01 19:29:45 dac.x2-nvme go-librespot[5514]: time="2025-03-01T19:29:45+08:00" level=info msg="zeroconf server listening on port 42611" Mar 01 19:29:46 dac.x2-nvme go-librespot[5514]: time="2025-03-01T19:29:46+08:00" level=debug msg="obtained new client token: AACEANRUUVicamwN60+Abcj9GwLuLHLj3i5po7xxflcF4L4/HHgocooAcpUG5voRVAV1qIBZOH5TjG11Bje+ph5cSNEbrhZD4OsOgcv5ka4WoyIe3iQD7BNYlbjwEvFmjGfeFNp2gfmCgF6AlP2kULRpYHPvn7sDzdZ6Z89Xfa5HGwV+aroFRuSpsip+MSvKvttllWGWkKEsO8yJtYvFxY0B7CDwiRM2aAxb2L49MZSp/iGkCMWZIlA=" Mar 01 19:29:46 dac.x2-nvme go-librespot[5514]: time="2025-03-01T19:29:46+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 01 19:29:46 dac.x2-nvme go-librespot[5514]: time="2025-03-01T19:29:46+08:00" level=debug msg="completed keyexchange" Mar 01 19:29:46 dac.x2-nvme go-librespot[5514]: time="2025-03-01T19:29:46+08:00" level=debug msg="completed challenge" Mar 01 19:29:46 dac.x2-nvme go-librespot[5514]: time="2025-03-01T19:29:46+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Mar 01 19:29:46 dac.x2-nvme systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 19:29:46 dac.x2-nvme systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 19:29:47 dac.x2-nvme volumio[1345]: info: Initializing connection to go-librespot Websocket Mar 01 19:29:47 dac.x2-nvme volumio[1345]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 19:29:48 dac.x2-nvme wpa_supplicant[1161]: wlan0: Failed to initiate sched scan Mar 01 19:29:49 dac.x2-nvme systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 19:29:49 dac.x2-nvme systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 158. Mar 01 19:29:49 dac.x2-nvme systemd[1]: Stopped go-librespot Daemon. Mar 01 19:29:49 dac.x2-nvme systemd[1]: Started go-librespot Daemon. Mar 01 19:29:49 dac.x2-nvme go-librespot[5523]: go-librespot daemon starting... Mar 01 19:29:49 dac.x2-nvme go-librespot[5523]: time="2025-03-01T19:29:49+08:00" level=info msg="running go-librespot 0.2.0" Mar 01 19:29:49 dac.x2-nvme go-librespot[5523]: time="2025-03-01T19:29:49+08:00" level=debug msg="app state loaded" Mar 01 19:29:49 dac.x2-nvme go-librespot[5523]: time="2025-03-01T19:29:49+08:00" level=debug msg="stored credentials not found" Mar 01 19:29:49 dac.x2-nvme go-librespot[5523]: time="2025-03-01T19:29:49+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 01 19:29:49 dac.x2-nvme volumio[1345]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 01 19:29:49 dac.x2-nvme volumio[1345]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 01 19:29:49 dac.x2-nvme volumio[1345]: info: Discovery: Getting this device information Mar 01 19:29:49 dac.x2-nvme volumio[1345]: info: CoreCommandRouter::volumioGetState Mar 01 19:29:49 dac.x2-nvme volumio[1345]: info: CorePlayQueue::getTrack 0 Mar 01 19:29:49 dac.x2-nvme volumio[1345]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 01 19:29:49 dac.x2-nvme go-librespot[5523]: time="2025-03-01T19:29:49+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 01 19:29:49 dac.x2-nvme go-librespot[5523]: time="2025-03-01T19:29:49+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Mar 01 19:29:49 dac.x2-nvme go-librespot[5523]: time="2025-03-01T19:29:49+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Mar 01 19:29:49 dac.x2-nvme go-librespot[5523]: time="2025-03-01T19:29:49+08:00" level=info msg="zeroconf server listening on port 44985" Mar 01 19:29:50 dac.x2-nvme go-librespot[5523]: time="2025-03-01T19:29:50+08:00" level=debug msg="obtained new client token: AADz9oidBa8kMTLWronXGATkMnpsphIdkV0QPXjQge/ViYcxCt8izyHBN1yLig2G6qXwV0kq3GGrRylvhUTIn5N2GBSbXgS1tQf42tb5PJSWjGPP57pFD+PtxjMHRiQcXG9l70wSgYC47wSVYIw+TZRtgbfUSzZQR4ZE7lUale8O4M0Ebyg3Q5rT4iPRQCr/lVQKpxJVZ/YXfSwH/Rv0+tqzY71IQT5mh8pBCSD9FrVa3lmAujyX" Mar 01 19:29:50 dac.x2-nvme go-librespot[5523]: time="2025-03-01T19:29:50+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 01 19:29:50 dac.x2-nvme go-librespot[5523]: time="2025-03-01T19:29:50+08:00" level=debug msg="completed keyexchange" Mar 01 19:29:50 dac.x2-nvme go-librespot[5523]: time="2025-03-01T19:29:50+08:00" level=debug msg="completed challenge" Mar 01 19:29:50 dac.x2-nvme go-librespot[5523]: time="2025-03-01T19:29:50+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Mar 01 19:29:50 dac.x2-nvme systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 19:29:50 dac.x2-nvme systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 19:29:50 dac.x2-nvme volumio[1345]: info: Initializing connection to go-librespot Websocket Mar 01 19:29:50 dac.x2-nvme volumio[1345]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 19:29:53 dac.x2-nvme systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 19:29:53 dac.x2-nvme systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 159. Mar 01 19:29:53 dac.x2-nvme systemd[1]: Stopped go-librespot Daemon. Mar 01 19:29:53 dac.x2-nvme systemd[1]: Started go-librespot Daemon. Mar 01 19:29:53 dac.x2-nvme go-librespot[5534]: go-librespot daemon starting... Mar 01 19:29:53 dac.x2-nvme go-librespot[5534]: time="2025-03-01T19:29:53+08:00" level=info msg="running go-librespot 0.2.0" Mar 01 19:29:53 dac.x2-nvme go-librespot[5534]: time="2025-03-01T19:29:53+08:00" level=debug msg="app state loaded" Mar 01 19:29:53 dac.x2-nvme go-librespot[5534]: time="2025-03-01T19:29:53+08:00" level=debug msg="stored credentials not found" Mar 01 19:29:53 dac.x2-nvme go-librespot[5534]: time="2025-03-01T19:29:53+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 01 19:29:53 dac.x2-nvme volumio[1345]: info: Initializing connection to go-librespot Websocket Mar 01 19:29:53 dac.x2-nvme volumio[1345]: info: Connection to go-librespot Websocket established Mar 01 19:29:53 dac.x2-nvme go-librespot[5534]: time="2025-03-01T19:29:53+08:00" level=debug msg="new websocket client" Mar 01 19:29:54 dac.x2-nvme go-librespot[5534]: time="2025-03-01T19:29:54+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 01 19:29:54 dac.x2-nvme go-librespot[5534]: time="2025-03-01T19:29:54+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 01 19:29:54 dac.x2-nvme go-librespot[5534]: time="2025-03-01T19:29:54+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 01 19:29:54 dac.x2-nvme go-librespot[5534]: time="2025-03-01T19:29:54+08:00" level=info msg="zeroconf server listening on port 38733" Mar 01 19:29:54 dac.x2-nvme go-librespot[5534]: time="2025-03-01T19:29:54+08:00" level=debug msg="obtained new client token: AAAD0M7xgKCZ6BLULs+8XvjiNF9nlhSzaa4tBYX8VfaEsQsZmKlSf2e9F/8pUiSi6DzhBZIF+BM1Hn0rg6AnuCkyTge3wsa74j7QrSdbIchb6AfWWdEDS3hsWwAjQyhkaoAQP/JjxliJ3hQk0vDYVra6wyN+Y/hMDcZwoBJh+sFwHwdY4TNFclvjj/WFkSPmiKODM1tUuKoylfC4JPvUl1/2WH33pmE2nmYalzt4Uzv+sd71s0X8EWE=" Mar 01 19:29:55 dac.x2-nvme go-librespot[5534]: time="2025-03-01T19:29:55+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 01 19:29:55 dac.x2-nvme go-librespot[5534]: time="2025-03-01T19:29:55+08:00" level=debug msg="completed keyexchange" Mar 01 19:29:55 dac.x2-nvme go-librespot[5534]: time="2025-03-01T19:29:55+08:00" level=debug msg="completed challenge" Mar 01 19:29:55 dac.x2-nvme go-librespot[5534]: time="2025-03-01T19:29:55+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Mar 01 19:29:55 dac.x2-nvme systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 19:29:55 dac.x2-nvme systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 19:29:55 dac.x2-nvme volumio[1345]: info: Connection to go-librespot Websocket closed Mar 01 19:29:55 dac.x2-nvme volumio[1345]: error: MyVolumio got a network error: A network error (such as timeout, interrupted connection or unreachable host) has occurred. Mar 01 19:29:55 dac.x2-nvme volumio[1345]: info: Retrying Login Due to Network Error Mar 01 19:29:56 dac.x2-nvme wpa_supplicant[1161]: wlan0: Failed to initiate sched scan Mar 01 19:29:56 dac.x2-nvme volumio[1345]: info: Getting Spotify volume Mar 01 19:29:56 dac.x2-nvme volumio[1345]: (node:1345) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 19:29:56 dac.x2-nvme volumio[1345]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Mar 01 19:29:56 dac.x2-nvme volumio[1345]: (node:1345) 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: 50) Mar 01 19:29:56 dac.x2-nvme volumio[1345]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Mar 01 19:29:56 dac.x2-nvme volumio[1345]: info: CoreCommandRouter::volumioGetState Mar 01 19:29:56 dac.x2-nvme volumio[1345]: info: CorePlayQueue::getTrack 0 Mar 01 19:29:58 dac.x2-nvme volumio[1345]: info: Initializing connection to go-librespot Websocket Mar 01 19:29:58 dac.x2-nvme volumio[1345]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 19:29:58 dac.x2-nvme systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 19:29:58 dac.x2-nvme systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 160. Mar 01 19:29:58 dac.x2-nvme systemd[1]: Stopped go-librespot Daemon. Mar 01 19:29:58 dac.x2-nvme systemd[1]: Started go-librespot Daemon. Mar 01 19:29:58 dac.x2-nvme go-librespot[5556]: go-librespot daemon starting... Mar 01 19:29:58 dac.x2-nvme go-librespot[5556]: time="2025-03-01T19:29:58+08:00" level=info msg="running go-librespot 0.2.0" Mar 01 19:29:58 dac.x2-nvme go-librespot[5556]: time="2025-03-01T19:29:58+08:00" level=debug msg="app state loaded" Mar 01 19:29:58 dac.x2-nvme go-librespot[5556]: time="2025-03-01T19:29:58+08:00" level=debug msg="stored credentials not found" Mar 01 19:29:58 dac.x2-nvme go-librespot[5556]: time="2025-03-01T19:29:58+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 01 19:29:58 dac.x2-nvme go-librespot[5556]: time="2025-03-01T19:29:58+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 01 19:29:58 dac.x2-nvme go-librespot[5556]: time="2025-03-01T19:29:58+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Mar 01 19:29:58 dac.x2-nvme go-librespot[5556]: time="2025-03-01T19:29:58+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Mar 01 19:29:58 dac.x2-nvme go-librespot[5556]: time="2025-03-01T19:29:58+08:00" level=info msg="zeroconf server listening on port 36709" Mar 01 19:29:59 dac.x2-nvme go-librespot[5556]: time="2025-03-01T19:29:59+08:00" level=debug msg="obtained new client token: AAAmvfSITi1WvRx2ZOeW79pxJelff044yDqOV6gYnpk0PtVbh1fsgAKY0J6RcPLoV3KKNa+DI2h0ZHHHsTUolDRoIyp6iqQth3Isi+BS1HdX1sXTswrf0YVwyy7Ogz07d9iWl1RiGGvCWjX98z76HWAI1JoQ9NzncPY8ocUHNCE45fv0Fp77eikZeFIcjBduETKTYhbzGydHcEWlKHT/HkjFJF9rZPA/dmiRLLZ5+8uk9wfLbfvQ" Mar 01 19:29:59 dac.x2-nvme go-librespot[5556]: time="2025-03-01T19:29:59+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 01 19:29:59 dac.x2-nvme go-librespot[5556]: time="2025-03-01T19:29:59+08:00" level=debug msg="completed keyexchange" Mar 01 19:29:59 dac.x2-nvme go-librespot[5556]: time="2025-03-01T19:29:59+08:00" level=debug msg="completed challenge" Mar 01 19:29:59 dac.x2-nvme go-librespot[5556]: time="2025-03-01T19:29:59+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Mar 01 19:29:59 dac.x2-nvme systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 19:29:59 dac.x2-nvme systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 19:30:01 dac.x2-nvme volumio[1345]: info: Initializing connection to go-librespot Websocket Mar 01 19:30:01 dac.x2-nvme volumio[1345]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 19:30:02 dac.x2-nvme systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 01 19:30:02 dac.x2-nvme systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 161. Mar 01 19:30:02 dac.x2-nvme systemd[1]: Stopped go-librespot Daemon. Mar 01 19:30:02 dac.x2-nvme systemd[1]: Started go-librespot Daemon. Mar 01 19:30:02 dac.x2-nvme go-librespot[5567]: go-librespot daemon starting... Mar 01 19:30:02 dac.x2-nvme go-librespot[5567]: time="2025-03-01T19:30:02+08:00" level=info msg="running go-librespot 0.2.0" Mar 01 19:30:02 dac.x2-nvme go-librespot[5567]: time="2025-03-01T19:30:02+08:00" level=debug msg="app state loaded" Mar 01 19:30:02 dac.x2-nvme go-librespot[5567]: time="2025-03-01T19:30:02+08:00" level=debug msg="stored credentials not found" Mar 01 19:30:02 dac.x2-nvme go-librespot[5567]: time="2025-03-01T19:30:02+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 01 19:30:03 dac.x2-nvme go-librespot[5567]: time="2025-03-01T19:30:03+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 01 19:30:03 dac.x2-nvme go-librespot[5567]: time="2025-03-01T19:30:03+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Mar 01 19:30:03 dac.x2-nvme go-librespot[5567]: time="2025-03-01T19:30:03+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Mar 01 19:30:03 dac.x2-nvme go-librespot[5567]: time="2025-03-01T19:30:03+08:00" level=info msg="zeroconf server listening on port 38109" Mar 01 19:30:03 dac.x2-nvme go-librespot[5567]: time="2025-03-01T19:30:03+08:00" level=debug msg="obtained new client token: AACZjI+oGqH9eVNgj69GFDGKKOlu7pvrYHOJ+bOv6WxZJjCJ2ShgTKrvnMN3nWJRA+Ng4fN+XGbkV6qqmOuAgSN/7K0T9dk2mLuKdEoDwDsO2WEc6AlK39FceP+Hf2N0sByQQBxy0Hws5Nebvq13FLYR6nHKYbtSiLh3G2jxWv4nOOZi8bdg3YxsDUm9cGVkagagX/sgnBRMx5ryFHOAzWIr/rFMn7Re9687y+79B6VTWOSqzPi8/sU=" Mar 01 19:30:03 dac.x2-nvme go-librespot[5567]: time="2025-03-01T19:30:03+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 01 19:30:03 dac.x2-nvme go-librespot[5567]: time="2025-03-01T19:30:03+08:00" level=debug msg="completed keyexchange" Mar 01 19:30:03 dac.x2-nvme go-librespot[5567]: time="2025-03-01T19:30:03+08:00" level=debug msg="completed challenge" Mar 01 19:30:03 dac.x2-nvme go-librespot[5567]: time="2025-03-01T19:30:03+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Mar 01 19:30:03 dac.x2-nvme systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 01 19:30:03 dac.x2-nvme systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 01 19:30:04 dac.x2-nvme volumio[1345]: info: Initializing connection to go-librespot Websocket Mar 01 19:30:04 dac.x2-nvme volumio[1345]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 01 19:30:04 dac.x2-nvme wpa_supplicant[1161]: wlan0: Failed to initiate sched scan Mar 01 19:30:05 dac.x2-nvme volumio[1345]: info: MyVolumio login type: Token Mar 01 19:30:05 dac.x2-nvme volumio[1345]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 01 19:30:05 dac.x2-nvme volumio[1345]: Error: connect ETIMEDOUT 199.59.148.209:443 Mar 01 19:30:05 dac.x2-nvme volumio[1345]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) { Mar 01 19:30:05 dac.x2-nvme volumio[1345]: errno: -110, Mar 01 19:30:05 dac.x2-nvme volumio[1345]: code: 'ETIMEDOUT', Mar 01 19:30:05 dac.x2-nvme volumio[1345]: syscall: 'connect', Mar 01 19:30:05 dac.x2-nvme volumio[1345]: address: '199.59.148.209', Mar 01 19:30:05 dac.x2-nvme volumio[1345]: port: 443 Mar 01 19:30:05 dac.x2-nvme volumio[1345]: } Mar 01 19:30:05 dac.x2-nvme volumio[1345]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 01 19:30:06 dac.x2-nvme sudo[5598]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-03-01 19:29 Mar 01 19:30:06 dac.x2-nvme sudo[5598]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="f6610a1100d2380eef33bd3004af43153c786f96" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="1c0e5daee99fe3a72cc38b0d1fe6cd78d7f001fe" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 16 Dec 2024 09:30:04 AM CET" VOLUMIO_VERSION="3.785" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fe0ac4b79aed19ccde4b5bd83d468193"