-- Logs begin at Mon 2025-02-24 15:46:49 CET, end at Tue 2025-02-25 21:20:34 CET. -- Feb 25 21:19:01 minidsp-shd volumio[626]: info: Getting Spotify volume Feb 25 21:19:01 minidsp-shd volumio[626]: (node:626) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 21:19:01 minidsp-shd volumio[626]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Feb 25 21:19:01 minidsp-shd volumio[626]: (node:626) 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: 268) Feb 25 21:19:01 minidsp-shd volumio[626]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Feb 25 21:19:01 minidsp-shd volumio[626]: info: CoreCommandRouter::volumioGetState Feb 25 21:19:01 minidsp-shd volumio[626]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 25 21:19:02 minidsp-shd volumio[626]: info: Initializing connection to go-librespot Websocket Feb 25 21:19:02 minidsp-shd volumio[626]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 21:19:02 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 25 21:19:02 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 780. Feb 25 21:19:02 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Feb 25 21:19:02 minidsp-shd systemd[1]: Started go-librespot Daemon. Feb 25 21:19:02 minidsp-shd go-librespot[15195]: Librespot-go daemon starting... Feb 25 21:19:02 minidsp-shd go-librespot[15195]: time="2025-02-25T21:19:02+01:00" level=info msg="generated new device id: 8d184d8251e233330ca2469399d0c70e520e5597" Feb 25 21:19:02 minidsp-shd go-librespot[15195]: time="2025-02-25T21:19:02+01:00" level=debug msg="stored credentials found for saschabies80" Feb 25 21:19:02 minidsp-shd go-librespot[15195]: time="2025-02-25T21:19:02+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 25 21:19:02 minidsp-shd go-librespot[15195]: time="2025-02-25T21:19:02+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 25 21:19:02 minidsp-shd go-librespot[15195]: time="2025-02-25T21:19:02+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 25 21:19:02 minidsp-shd go-librespot[15195]: time="2025-02-25T21:19:02+01:00" level=debug msg="zeroconf server listening on port 39349" Feb 25 21:19:03 minidsp-shd go-librespot[15195]: time="2025-02-25T21:19:03+01:00" level=debug msg="obtained new client token: AAC9c9NYWR9m6SjIq+p90CuEY1etSjxdi93fN1f4B5w6ovKuDu7RhuGaAou7PM5VwZbCx2Oh+lYspyj2eE4U6c65184nu30kqtlgTa33Ha6N+GTzmLGpY9TMn7PI03UOZPlb4M+K5LrCRjzalQ7m2wSUQceRIirXG63rRzbNFGyXah9BS9UpNSoQurN6sTpwm2hlAxG77NmJrTek0aMD27wCe1Qnblxm/iegUQ2c+/6TZpP0CkLB3utcL0k=" Feb 25 21:19:03 minidsp-shd go-librespot[15195]: time="2025-02-25T21:19:03+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070 (error: dial tcp 34.158.1.133:4070: connect: connection refused), retrying with a different AP" Feb 25 21:19:03 minidsp-shd go-librespot[15195]: time="2025-02-25T21:19:03+01:00" level=info msg="connected to ap-gew4.spotify.com:443" Feb 25 21:19:03 minidsp-shd go-librespot[15195]: time="2025-02-25T21:19:03+01:00" level=debug msg="completed keyexchange" Feb 25 21:19:03 minidsp-shd go-librespot[15195]: time="2025-02-25T21:19:03+01:00" level=debug msg="completed challenge" Feb 25 21:19:03 minidsp-shd go-librespot[15195]: time="2025-02-25T21:19:03+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 25 21:19:03 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 21:19:03 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 21:19:05 minidsp-shd volumio[626]: info: Initializing connection to go-librespot Websocket Feb 25 21:19:05 minidsp-shd volumio[626]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 21:19:06 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 25 21:19:06 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 781. Feb 25 21:19:06 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Feb 25 21:19:06 minidsp-shd systemd[1]: Started go-librespot Daemon. Feb 25 21:19:06 minidsp-shd go-librespot[15211]: Librespot-go daemon starting... Feb 25 21:19:06 minidsp-shd go-librespot[15211]: time="2025-02-25T21:19:06+01:00" level=info msg="generated new device id: 734c5f3057c5817089785b9c6790eedba3446162" Feb 25 21:19:06 minidsp-shd go-librespot[15211]: time="2025-02-25T21:19:06+01:00" level=debug msg="stored credentials found for saschabies80" Feb 25 21:19:07 minidsp-shd go-librespot[15211]: time="2025-02-25T21:19:07+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 25 21:19:07 minidsp-shd go-librespot[15211]: time="2025-02-25T21:19:07+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 25 21:19:07 minidsp-shd go-librespot[15211]: time="2025-02-25T21:19:07+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 25 21:19:07 minidsp-shd go-librespot[15211]: time="2025-02-25T21:19:07+01:00" level=debug msg="zeroconf server listening on port 44995" Feb 25 21:19:07 minidsp-shd go-librespot[15211]: time="2025-02-25T21:19:07+01:00" level=debug msg="obtained new client token: AADJ1puMN6B2vHLq//nLVL5tUVc5kuqSIP/5hgxwlC3oO+Uz/Q85FY0HD4p/db7EYyIJ7J1CqNB7yxYdupg5kxxK3/qPhdcWdFcXBZbWVadKKub77ZqkBp+DZY6Rd1jDOAFXzlQWdx7H5B2V4X4s3PKghLVFJOWOXMO5WuBX0EzKIebgVzSam8k4N5xdNZJDI7b12yVK2BTJBF/OU79glnvgVd1ZduZSzxZ96+4lTHrj19xBo9nvA21Zt3Lnww==" Feb 25 21:19:07 minidsp-shd go-librespot[15211]: time="2025-02-25T21:19:07+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 25 21:19:07 minidsp-shd go-librespot[15211]: time="2025-02-25T21:19:07+01:00" level=debug msg="completed keyexchange" Feb 25 21:19:07 minidsp-shd go-librespot[15211]: time="2025-02-25T21:19:07+01:00" level=debug msg="completed challenge" Feb 25 21:19:07 minidsp-shd go-librespot[15211]: time="2025-02-25T21:19:07+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 25 21:19:07 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 21:19:07 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 21:19:08 minidsp-shd volumio[626]: info: Initializing connection to go-librespot Websocket Feb 25 21:19:08 minidsp-shd volumio[626]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 21:19:11 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 25 21:19:11 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 782. Feb 25 21:19:11 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Feb 25 21:19:11 minidsp-shd systemd[1]: Started go-librespot Daemon. Feb 25 21:19:11 minidsp-shd go-librespot[15230]: Librespot-go daemon starting... Feb 25 21:19:11 minidsp-shd go-librespot[15230]: time="2025-02-25T21:19:11+01:00" level=info msg="generated new device id: 3ce900779933153c1e18a105b9a2f4c0fc46e12f" Feb 25 21:19:11 minidsp-shd go-librespot[15230]: time="2025-02-25T21:19:11+01:00" level=debug msg="stored credentials found for saschabies80" Feb 25 21:19:11 minidsp-shd go-librespot[15230]: time="2025-02-25T21:19:11+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 25 21:19:11 minidsp-shd go-librespot[15230]: time="2025-02-25T21:19:11+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 25 21:19:11 minidsp-shd go-librespot[15230]: time="2025-02-25T21:19:11+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 25 21:19:11 minidsp-shd go-librespot[15230]: time="2025-02-25T21:19:11+01:00" level=debug msg="zeroconf server listening on port 34915" Feb 25 21:19:11 minidsp-shd volumio[626]: info: Initializing connection to go-librespot Websocket Feb 25 21:19:11 minidsp-shd go-librespot[15230]: time="2025-02-25T21:19:11+01:00" level=debug msg="new websocket client" Feb 25 21:19:11 minidsp-shd volumio[626]: info: Connection to go-librespot Websocket established Feb 25 21:19:11 minidsp-shd go-librespot[15230]: time="2025-02-25T21:19:11+01:00" level=debug msg="obtained new client token: AABhZUrpH+WVWRwGlfc6yl7mpnhrpP+V3yr7Z9rxlL1K3vwFrKAv8Ht2/21l1unhtV6irsllvN0PdGy7I68hZLBaRygGJuDz7zXKIv43Q5mPSaG90Y2IzvD45WKanBY30kmh1qYa0+JVAb+Eq9tgeyykMnba/51yf9Yy4dIRFZLgSsvUzMpfq2GkQIUL1Ifpvztg5ceFb2ogq7KQ7MKaMvh5pSkrs+QQgdwhNEoBUaPEm3BaQAaYZoUy3/JBOw==" Feb 25 21:19:11 minidsp-shd go-librespot[15230]: time="2025-02-25T21:19:11+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 25 21:19:11 minidsp-shd go-librespot[15230]: time="2025-02-25T21:19:11+01:00" level=debug msg="completed keyexchange" Feb 25 21:19:12 minidsp-shd go-librespot[15230]: time="2025-02-25T21:19:12+01:00" level=debug msg="completed challenge" Feb 25 21:19:12 minidsp-shd go-librespot[15230]: time="2025-02-25T21:19:12+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 25 21:19:12 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 21:19:12 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 21:19:12 minidsp-shd volumio[626]: info: Connection to go-librespot Websocket closed Feb 25 21:19:14 minidsp-shd volumio[626]: info: Getting Spotify volume Feb 25 21:19:14 minidsp-shd volumio[626]: (node:626) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 21:19:14 minidsp-shd volumio[626]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Feb 25 21:19:14 minidsp-shd volumio[626]: (node:626) 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: 269) Feb 25 21:19:14 minidsp-shd volumio[626]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Feb 25 21:19:14 minidsp-shd volumio[626]: info: CoreCommandRouter::volumioGetState Feb 25 21:19:14 minidsp-shd volumio[626]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 25 21:19:15 minidsp-shd volumio[626]: info: Initializing connection to go-librespot Websocket Feb 25 21:19:15 minidsp-shd volumio[626]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 21:19:15 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 25 21:19:15 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 783. Feb 25 21:19:15 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Feb 25 21:19:15 minidsp-shd systemd[1]: Started go-librespot Daemon. Feb 25 21:19:15 minidsp-shd go-librespot[15247]: Librespot-go daemon starting... Feb 25 21:19:15 minidsp-shd go-librespot[15247]: time="2025-02-25T21:19:15+01:00" level=info msg="generated new device id: d1f522c40b0a22db783f9591714065df5825bb91" Feb 25 21:19:15 minidsp-shd go-librespot[15247]: time="2025-02-25T21:19:15+01:00" level=debug msg="stored credentials found for saschabies80" Feb 25 21:19:15 minidsp-shd go-librespot[15247]: time="2025-02-25T21:19:15+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 25 21:19:15 minidsp-shd go-librespot[15247]: time="2025-02-25T21:19:15+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 25 21:19:15 minidsp-shd go-librespot[15247]: time="2025-02-25T21:19:15+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 25 21:19:15 minidsp-shd go-librespot[15247]: time="2025-02-25T21:19:15+01:00" level=debug msg="zeroconf server listening on port 36701" Feb 25 21:19:15 minidsp-shd go-librespot[15247]: time="2025-02-25T21:19:15+01:00" level=debug msg="obtained new client token: AAA6iguNpe0dJ0FkPhG8ZRvt1AJLGIoCj9axpKLbgLbkC3Gjn3l9V7jhu8q6C0P+HfvUwLEWjV2lAia4e3uMX25XWLBTLJn3UxR5KvEKNgkpP+JyPwF/lEmZYVZKPgmVDly2icbz/4bYMVfkdnWfDSa8jiLCw0V1jA1yGcIessOzoy2l2fghPEQDGTaX9lFT6JJ/726cfBdeBUdxhiBsVolHILqENMYu1jOAGhDLiFxXlnkuPbU2ttD+lKS7Sg==" Feb 25 21:19:15 minidsp-shd go-librespot[15247]: time="2025-02-25T21:19:15+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 25 21:19:15 minidsp-shd go-librespot[15247]: time="2025-02-25T21:19:15+01:00" level=debug msg="completed keyexchange" Feb 25 21:19:16 minidsp-shd go-librespot[15247]: time="2025-02-25T21:19:16+01:00" level=debug msg="completed challenge" Feb 25 21:19:16 minidsp-shd go-librespot[15247]: time="2025-02-25T21:19:16+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 25 21:19:16 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 21:19:16 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 21:19:18 minidsp-shd volumio[626]: info: Initializing connection to go-librespot Websocket Feb 25 21:19:18 minidsp-shd volumio[626]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 21:19:19 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 25 21:19:19 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 784. Feb 25 21:19:19 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Feb 25 21:19:19 minidsp-shd systemd[1]: Started go-librespot Daemon. Feb 25 21:19:19 minidsp-shd go-librespot[15263]: Librespot-go daemon starting... Feb 25 21:19:19 minidsp-shd go-librespot[15263]: time="2025-02-25T21:19:19+01:00" level=info msg="generated new device id: 4101982d58347f3c798f8398651744b5dfc268b0" Feb 25 21:19:19 minidsp-shd go-librespot[15263]: time="2025-02-25T21:19:19+01:00" level=debug msg="stored credentials found for saschabies80" Feb 25 21:19:19 minidsp-shd volumio[626]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 25 21:19:19 minidsp-shd volumio[626]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 25 21:19:19 minidsp-shd volumio[626]: info: Discovery: Getting this device information Feb 25 21:19:19 minidsp-shd volumio[626]: info: CoreCommandRouter::volumioGetState Feb 25 21:19:19 minidsp-shd volumio[626]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 25 21:19:19 minidsp-shd go-librespot[15263]: time="2025-02-25T21:19:19+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 25 21:19:19 minidsp-shd go-librespot[15263]: time="2025-02-25T21:19:19+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 25 21:19:19 minidsp-shd go-librespot[15263]: time="2025-02-25T21:19:19+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 25 21:19:19 minidsp-shd go-librespot[15263]: time="2025-02-25T21:19:19+01:00" level=debug msg="zeroconf server listening on port 40885" Feb 25 21:19:20 minidsp-shd go-librespot[15263]: time="2025-02-25T21:19:20+01:00" level=debug msg="obtained new client token: AAD/Y0AWjy6EGJ27fwyvM7xGB4E9ZJfJ86qIH6n1N7Y5VKwkItZ7E/jyqEIzdUuipVx1N4BtEDy9l1wbLKwAnCQgS3mF9PhtJv6r/3MLHAUvh2m46mf+Vk6X3ysI/aFBmzvcG8z6ikpp7eGK2Kv0vOUIESnINyKkOlIRM1D0UCqVOcbw/gWBfc7n6id2E7VsAn4+0djPIhG8qKMhL8ipr0iCj8RZTTqNLtozy310VYbIEE5JAFAD3m9x" Feb 25 21:19:20 minidsp-shd go-librespot[15263]: time="2025-02-25T21:19:20+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 25 21:19:20 minidsp-shd go-librespot[15263]: time="2025-02-25T21:19:20+01:00" level=debug msg="completed keyexchange" Feb 25 21:19:20 minidsp-shd go-librespot[15263]: time="2025-02-25T21:19:20+01:00" level=debug msg="completed challenge" Feb 25 21:19:20 minidsp-shd go-librespot[15263]: time="2025-02-25T21:19:20+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 25 21:19:20 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 21:19:20 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 21:19:21 minidsp-shd volumio[626]: info: Initializing connection to go-librespot Websocket Feb 25 21:19:21 minidsp-shd volumio[626]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 21:19:23 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 25 21:19:23 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 785. Feb 25 21:19:23 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Feb 25 21:19:23 minidsp-shd systemd[1]: Started go-librespot Daemon. Feb 25 21:19:23 minidsp-shd go-librespot[15279]: Librespot-go daemon starting... Feb 25 21:19:23 minidsp-shd go-librespot[15279]: time="2025-02-25T21:19:23+01:00" level=info msg="generated new device id: 222b60d1d22a983fb9738a772e59128e5ae9fb35" Feb 25 21:19:23 minidsp-shd go-librespot[15279]: time="2025-02-25T21:19:23+01:00" level=debug msg="stored credentials found for saschabies80" Feb 25 21:19:24 minidsp-shd go-librespot[15279]: time="2025-02-25T21:19:24+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 25 21:19:24 minidsp-shd go-librespot[15279]: time="2025-02-25T21:19:24+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 25 21:19:24 minidsp-shd go-librespot[15279]: time="2025-02-25T21:19:24+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 25 21:19:24 minidsp-shd go-librespot[15279]: time="2025-02-25T21:19:24+01:00" level=debug msg="zeroconf server listening on port 44623" Feb 25 21:19:24 minidsp-shd volumio[626]: info: Initializing connection to go-librespot Websocket Feb 25 21:19:24 minidsp-shd go-librespot[15279]: time="2025-02-25T21:19:24+01:00" level=debug msg="obtained new client token: AAAXe724loab1G5ysPVs3YcjxrmW2H8K1+tlry9TNX2j/C5iMpLMX3hm6HTFzgAYV2eLyWkIK3I34uSR8zWAI59q04/3doxXNZ6ZW3XlDVv2sS4a48zSeMkxcxm06oxv4d+Qi7l5O9HmDxZJEdU18uKJkQkHdmEb65L9n1617mWmvA7tbYECiHtJN0tgwmF+J6IULq8W41nvb+TS+D+smYHWkrYDuSVJzJsfhvwxlPt2nqNVJNyLSNF03i0=" Feb 25 21:19:24 minidsp-shd go-librespot[15279]: time="2025-02-25T21:19:24+01:00" level=debug msg="new websocket client" Feb 25 21:19:24 minidsp-shd volumio[626]: info: Connection to go-librespot Websocket established Feb 25 21:19:24 minidsp-shd go-librespot[15279]: time="2025-02-25T21:19:24+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 25 21:19:24 minidsp-shd go-librespot[15279]: time="2025-02-25T21:19:24+01:00" level=debug msg="completed keyexchange" Feb 25 21:19:24 minidsp-shd go-librespot[15279]: time="2025-02-25T21:19:24+01:00" level=debug msg="completed challenge" Feb 25 21:19:24 minidsp-shd go-librespot[15279]: time="2025-02-25T21:19:24+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Feb 25 21:19:24 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 21:19:24 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 21:19:24 minidsp-shd volumio[626]: info: Connection to go-librespot Websocket closed Feb 25 21:19:27 minidsp-shd volumio[626]: info: Getting Spotify volume Feb 25 21:19:27 minidsp-shd volumio[626]: (node:626) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 21:19:27 minidsp-shd volumio[626]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Feb 25 21:19:27 minidsp-shd volumio[626]: (node:626) 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: 270) Feb 25 21:19:27 minidsp-shd volumio[626]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Feb 25 21:19:27 minidsp-shd volumio[626]: info: CoreCommandRouter::volumioGetState Feb 25 21:19:27 minidsp-shd volumio[626]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 25 21:19:27 minidsp-shd volumio[626]: info: Initializing connection to go-librespot Websocket Feb 25 21:19:27 minidsp-shd volumio[626]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 21:19:28 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 25 21:19:28 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 786. Feb 25 21:19:28 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Feb 25 21:19:28 minidsp-shd systemd[1]: Started go-librespot Daemon. Feb 25 21:19:28 minidsp-shd go-librespot[15296]: Librespot-go daemon starting... Feb 25 21:19:28 minidsp-shd go-librespot[15296]: time="2025-02-25T21:19:28+01:00" level=info msg="generated new device id: 9ad4af4e73403dd3b0d88e91fae2954c5491163b" Feb 25 21:19:28 minidsp-shd go-librespot[15296]: time="2025-02-25T21:19:28+01:00" level=debug msg="stored credentials found for saschabies80" Feb 25 21:19:28 minidsp-shd go-librespot[15296]: time="2025-02-25T21:19:28+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 25 21:19:28 minidsp-shd go-librespot[15296]: time="2025-02-25T21:19:28+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 25 21:19:28 minidsp-shd go-librespot[15296]: time="2025-02-25T21:19:28+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 25 21:19:28 minidsp-shd go-librespot[15296]: time="2025-02-25T21:19:28+01:00" level=debug msg="zeroconf server listening on port 46473" Feb 25 21:19:28 minidsp-shd go-librespot[15296]: time="2025-02-25T21:19:28+01:00" level=debug msg="obtained new client token: AACRHqOa6/Y825YshUc1kYUVIxAlgxdCMwbUBxZn/QIOIOKb6ir5inLRk5VbzJPf7ka5p4BxJRCuTwKR02kQuoeopdVZPXswyqH8puqs2YW4IkBQJQD9UQQZZhY3Px99k0TWIsRTDlgvi//FnJZfDhDvLciwA/sWsYHHh4cfL8SHO7S9oBDe0OCFp+lIRmd4eiOWJ2xkM3a2H3kA0Saw5QqEnGiNrnQJRx2G9dVDb8EqQk+HjgHV0n+6tS1YbA==" Feb 25 21:19:28 minidsp-shd go-librespot[15296]: time="2025-02-25T21:19:28+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 25 21:19:30 minidsp-shd volumio[626]: info: Initializing connection to go-librespot Websocket Feb 25 21:19:30 minidsp-shd go-librespot[15296]: time="2025-02-25T21:19:30+01:00" level=debug msg="new websocket client" Feb 25 21:19:30 minidsp-shd volumio[626]: info: Connection to go-librespot Websocket established Feb 25 21:19:33 minidsp-shd volumio[626]: info: Getting Spotify volume Feb 25 21:19:33 minidsp-shd volumio[626]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Feb 25 21:19:34 minidsp-shd volumio[626]: info: CoreCommandRouter::volumioGetState Feb 25 21:19:34 minidsp-shd volumio[626]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 25 21:19:49 minidsp-shd volumio[626]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 25 21:19:49 minidsp-shd volumio[626]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 25 21:19:49 minidsp-shd volumio[626]: info: Discovery: Getting this device information Feb 25 21:19:49 minidsp-shd volumio[626]: info: CoreCommandRouter::volumioGetState Feb 25 21:19:49 minidsp-shd volumio[626]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 25 21:20:19 minidsp-shd volumio[626]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 25 21:20:19 minidsp-shd volumio[626]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 25 21:20:19 minidsp-shd volumio[626]: info: Discovery: Getting this device information Feb 25 21:20:19 minidsp-shd volumio[626]: info: CoreCommandRouter::volumioGetState Feb 25 21:20:19 minidsp-shd volumio[626]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 25 21:20:22 minidsp-shd volumio[626]: info: CoreCommandRouter::volumioGetState Feb 25 21:20:24 minidsp-shd volumio[626]: info: Executing endpoint metavolumio Feb 25 21:20:24 minidsp-shd volumio[626]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 25 21:20:25 minidsp-shd volumio[626]: info: Executing endpoint metavolumio Feb 25 21:20:25 minidsp-shd volumio[626]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 25 21:20:25 minidsp-shd volumio[626]: info: Executing endpoint metavolumio Feb 25 21:20:25 minidsp-shd volumio[626]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 25 21:20:33 minidsp-shd volumio[626]: Searching all installed plugins Feb 25 21:20:33 minidsp-shd volumio[626]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 21:20:33 minidsp-shd volumio[626]: info: CoreCommandRouter::executeOnPlugin: , search Feb 25 21:20:33 minidsp-shd volumio[626]: info: CoreCommandRouter::executeOnPlugin: mpd , search Feb 25 21:20:33 minidsp-shd volumio[626]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search Feb 25 21:20:33 minidsp-shd volumio[626]: info: CoreCommandRouter::executeOnPlugin: last_100 , search Feb 25 21:20:33 minidsp-shd volumio[626]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 Feb 25 21:20:33 minidsp-shd volumio[626]: info: CoreCommandRouter::executeOnPlugin: webradio , search Feb 25 21:20:33 minidsp-shd volumio[626]: info: CoreCommandRouter::executeOnPlugin: calmradio , search Feb 25 21:20:33 minidsp-shd volumio[626]: info: [1740514833265] ControllerCalmRadio::searchCategories Feb 25 21:20:33 minidsp-shd volumio[626]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 25 21:20:33 minidsp-shd volumio[626]: TypeError: Cannot read property 'cats' of undefined Feb 25 21:20:33 minidsp-shd volumio[626]: at ControllerCalmRadio.searchCategories (/data/plugins/music_service/calmradio/index.js:615:42) Feb 25 21:20:33 minidsp-shd volumio[626]: at ControllerCalmRadio.search (/data/plugins/music_service/calmradio/index.js:665:28) Feb 25 21:20:33 minidsp-shd volumio[626]: at CoreCommandRouter.executeOnPlugin (/volumio/app/index.js:1077:32) Feb 25 21:20:33 minidsp-shd volumio[626]: at CoreMusicLibrary.searchOnPlugin (/volumio/app/musiclibrary.js:668:44) Feb 25 21:20:33 minidsp-shd volumio[626]: at CoreMusicLibrary.search (/volumio/app/musiclibrary.js:455:27) Feb 25 21:20:33 minidsp-shd volumio[626]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:457:44) Feb 25 21:20:33 minidsp-shd volumio[626]: at Socket.emit (events.js:400:28) Feb 25 21:20:33 minidsp-shd volumio[626]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 Feb 25 21:20:33 minidsp-shd volumio[626]: at processTicksAndRejections (internal/process/task_queues.js:77:11) Feb 25 21:20:33 minidsp-shd volumio[626]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 25 21:20:34 minidsp-shd sudo[15480]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-02-25 21:19 Feb 25 21:20:34 minidsp-shd sudo[15480]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="17fcb754ddd6bd152b01008c46cc4ba1ca48bf35" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="281cefcd7a302aa7cfba569185cf7aae19b8c376" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="minidspshd" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 22 Mar 2024 03:13:25 PM CET" VOLUMIO_VERSION="3.608" VOLUMIO_HARDWARE="nanopineo3" VOLUMIO_DEVICENAME="Nanopi Neo3" VOLUMIO_VENDOR="miniDSP" VOLUMIO_MODEL="SHD" VOLUMIO_VENDOR_MODEL="miniDSP SHD" VOLUMIO_HASH="18533ba33f8f92d7e7e459bb30f70beb"