-- Logs begin at Wed 2025-04-30 20:36:16 UTC, end at Wed 2025-04-30 22:32:32 UTC. -- Apr 30 22:31:00 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 30 22:31:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2669. Apr 30 22:31:00 volumio systemd[1]: Stopped go-librespot Daemon. Apr 30 22:31:00 volumio systemd[1]: Started go-librespot Daemon. Apr 30 22:31:00 volumio go-librespot[4423]: Librespot-go daemon starting... Apr 30 22:31:01 volumio go-librespot[4423]: time="2025-04-30T22:31:01Z" level=info msg="generated new device id: 6d553db19f8ee84b5f6066426dcfca143d4fb5b0" Apr 30 22:31:01 volumio go-librespot[4423]: time="2025-04-30T22:31:01Z" level=debug msg="stored credentials found for rrx4tvu533kv6l5jtlxq0bnr3" Apr 30 22:31:01 volumio go-librespot[4423]: time="2025-04-30T22:31:01Z" 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]" Apr 30 22:31:01 volumio go-librespot[4423]: time="2025-04-30T22:31:01Z" 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]" Apr 30 22:31:01 volumio go-librespot[4423]: time="2025-04-30T22:31:01Z" 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]" Apr 30 22:31:01 volumio go-librespot[4423]: time="2025-04-30T22:31:01Z" level=debug msg="zeroconf server listening on port 34135" Apr 30 22:31:01 volumio go-librespot[4423]: time="2025-04-30T22:31:01Z" level=debug msg="obtained new client token: AAB7UIsZtm5IG4i3gDSHRNjxeuBTuUsQdTg4a/REK7DmZU/IGchramiaTRjdaPUA2LNzvT+DDUqnamX3v3RLFyhhJFHF5tmbn+Bb+c9SClNY0gXtdY62yx6cTnxDMZp5CXx/Gm7NP1oAjDuQ1vjyxCrjYAq6mT+hqYcEMszkahQHPm1Kfs3bvconOrilOScfdWp+3HN1U76cFXimI++kxo64hcWv5fdmj41p1NT8R/hyDIVHny6Opa4u/w==" Apr 30 22:31:01 volumio go-librespot[4423]: time="2025-04-30T22:31:01Z" level=info msg="connected to ap-gew4.spotify.com:4070" Apr 30 22:31:01 volumio go-librespot[4423]: time="2025-04-30T22:31:01Z" level=debug msg="completed keyexchange" Apr 30 22:31:01 volumio go-librespot[4423]: time="2025-04-30T22:31:01Z" level=debug msg="completed challenge" Apr 30 22:31:01 volumio go-librespot[4423]: time="2025-04-30T22:31:01Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 30 22:31:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 30 22:31:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 30 22:31:02 volumio volumio[862]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 30 22:31:02 volumio volumio[862]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 30 22:31:02 volumio volumio[862]: info: Discovery: Getting this device information Apr 30 22:31:02 volumio volumio[862]: info: CoreCommandRouter::volumioGetState Apr 30 22:31:02 volumio volumio[862]: info: CorePlayQueue::getTrack 0 Apr 30 22:31:02 volumio volumio[862]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 30 22:31:02 volumio volumio[862]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 30 22:31:02 volumio volumio[862]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Apr 30 22:31:02 volumio volumio[862]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 30 22:31:02 volumio volumio[862]: info: Initializing connection to go-librespot Websocket Apr 30 22:31:02 volumio volumio[862]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 30 22:31:04 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 30 22:31:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2670. Apr 30 22:31:04 volumio systemd[1]: Stopped go-librespot Daemon. Apr 30 22:31:04 volumio systemd[1]: Started go-librespot Daemon. Apr 30 22:31:04 volumio go-librespot[4445]: Librespot-go daemon starting... Apr 30 22:31:05 volumio go-librespot[4445]: time="2025-04-30T22:31:05Z" level=info msg="generated new device id: d4f7700f886f106c1d8f36bf950c3617f7b00780" Apr 30 22:31:05 volumio go-librespot[4445]: time="2025-04-30T22:31:05Z" level=debug msg="stored credentials found for rrx4tvu533kv6l5jtlxq0bnr3" Apr 30 22:31:05 volumio go-librespot[4445]: time="2025-04-30T22:31:05Z" 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]" Apr 30 22:31:05 volumio go-librespot[4445]: time="2025-04-30T22:31:05Z" 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]" Apr 30 22:31:05 volumio go-librespot[4445]: time="2025-04-30T22:31:05Z" 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]" Apr 30 22:31:05 volumio go-librespot[4445]: time="2025-04-30T22:31:05Z" level=debug msg="zeroconf server listening on port 34279" Apr 30 22:31:05 volumio go-librespot[4445]: time="2025-04-30T22:31:05Z" level=debug msg="obtained new client token: AAC+JVGLaE6Pr37LEyKS615ZK/jx/D1kyuvsgKbRs6Ho8YWbosR/Vrwd5EqpeKbx9/B5VbkQNg1ISJU4CkIzdGOTY8p8KEvC//4BfnT2c0tWt3Or1Eoj1+WN4kShb3MOTkY+Us4HVNbdgLEnJ7giuCF+3SP0zaunk8QJSHqxsiGWPvkUJQNm0V8AoiH9fXYa4IEA1fWbzgvu0WKzqNYzxAy8QN3qJkGz+oX6gz0fEvMm7K52bC5BsKd+PA==" Apr 30 22:31:05 volumio go-librespot[4445]: time="2025-04-30T22:31:05Z" level=info msg="connected to ap-gew4.spotify.com:4070" Apr 30 22:31:05 volumio go-librespot[4445]: time="2025-04-30T22:31:05Z" level=debug msg="completed keyexchange" Apr 30 22:31:05 volumio go-librespot[4445]: time="2025-04-30T22:31:05Z" level=debug msg="completed challenge" Apr 30 22:31:05 volumio go-librespot[4445]: time="2025-04-30T22:31:05Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 30 22:31:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 30 22:31:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 30 22:31:05 volumio volumio[862]: info: CoreCommandRouter::volumioGetState Apr 30 22:31:05 volumio volumio[862]: info: CorePlayQueue::getTrack 0 Apr 30 22:31:05 volumio volumio[862]: info: Listing playlists Apr 30 22:31:05 volumio volumio[862]: info: Listing playlists Apr 30 22:31:05 volumio volumio[862]: info: Initializing connection to go-librespot Websocket Apr 30 22:31:05 volumio volumio[862]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 30 22:31:08 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 30 22:31:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2671. Apr 30 22:31:08 volumio systemd[1]: Stopped go-librespot Daemon. Apr 30 22:31:08 volumio volumio[862]: info: Initializing connection to go-librespot Websocket Apr 30 22:31:08 volumio volumio[862]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 30 22:31:08 volumio systemd[1]: Started go-librespot Daemon. Apr 30 22:31:09 volumio go-librespot[4465]: Librespot-go daemon starting... Apr 30 22:31:09 volumio go-librespot[4465]: time="2025-04-30T22:31:09Z" level=info msg="generated new device id: c0cbf292debd0a01eccdcea57bcc42c7a11bc2f4" Apr 30 22:31:09 volumio go-librespot[4465]: time="2025-04-30T22:31:09Z" level=debug msg="stored credentials found for rrx4tvu533kv6l5jtlxq0bnr3" Apr 30 22:31:09 volumio go-librespot[4465]: time="2025-04-30T22:31:09Z" 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]" Apr 30 22:31:09 volumio go-librespot[4465]: time="2025-04-30T22:31:09Z" 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]" Apr 30 22:31:09 volumio go-librespot[4465]: time="2025-04-30T22:31:09Z" 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]" Apr 30 22:31:09 volumio go-librespot[4465]: time="2025-04-30T22:31:09Z" level=debug msg="zeroconf server listening on port 37537" Apr 30 22:31:09 volumio go-librespot[4465]: time="2025-04-30T22:31:09Z" level=debug msg="obtained new client token: AACG3ucnoM5J9M7WCccqBbgmm/jwBlAgvBlSSqJOGrM5eygpg5gP5N8m5kx/5kc6GHha2iQ4y7Ul5wJmD4ROqr4tJeSSysSu7dAUfM2p+rJnC7lrVgrTwh9krfOX2zWI5RbTMlPGxU10+maxHxfHUKQRcL4EfuGEYkYQLK1b0NYHkD+0Pc0W1AgFG+RNOzAEmAkaNqMvipPByCh3ADQm7AQy18ejkwKNCKCTGaWKnbKUM9IyRrYAaS8gVg==" Apr 30 22:31:09 volumio go-librespot[4465]: time="2025-04-30T22:31:09Z" level=info msg="connected to ap-gew4.spotify.com:4070" Apr 30 22:31:09 volumio go-librespot[4465]: time="2025-04-30T22:31:09Z" level=debug msg="completed keyexchange" Apr 30 22:31:09 volumio go-librespot[4465]: time="2025-04-30T22:31:09Z" level=debug msg="completed challenge" Apr 30 22:31:09 volumio go-librespot[4465]: time="2025-04-30T22:31:09Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 30 22:31:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 30 22:31:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 30 22:31:11 volumio volumio[862]: info: Initializing connection to go-librespot Websocket Apr 30 22:31:11 volumio volumio[862]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 30 22:31:12 volumio volumio[862]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 30 22:31:12 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 30 22:31:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2672. Apr 30 22:31:12 volumio systemd[1]: Stopped go-librespot Daemon. Apr 30 22:31:12 volumio systemd[1]: Started go-librespot Daemon. Apr 30 22:31:12 volumio go-librespot[4491]: Librespot-go daemon starting... Apr 30 22:31:13 volumio go-librespot[4491]: time="2025-04-30T22:31:13Z" level=info msg="generated new device id: 5abc0fe70f0dace8abe40fb66afed660bc417bf6" Apr 30 22:31:13 volumio go-librespot[4491]: time="2025-04-30T22:31:13Z" level=debug msg="stored credentials found for rrx4tvu533kv6l5jtlxq0bnr3" Apr 30 22:31:13 volumio go-librespot[4491]: time="2025-04-30T22:31:13Z" 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]" Apr 30 22:31:13 volumio go-librespot[4491]: time="2025-04-30T22:31:13Z" 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]" Apr 30 22:31:13 volumio go-librespot[4491]: time="2025-04-30T22:31:13Z" 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]" Apr 30 22:31:13 volumio go-librespot[4491]: time="2025-04-30T22:31:13Z" level=debug msg="zeroconf server listening on port 45339" Apr 30 22:31:13 volumio go-librespot[4491]: time="2025-04-30T22:31:13Z" level=debug msg="obtained new client token: AAAqQS/m9AR8mpD5EFKUoQwWyTVnVya/J6mXmsireWIc4tMI/Z9Pa6FdlDbv/E1gwNfy+9Smzg4V9PfLW6l52L/iOUf6L/xNmvoHM9q13gs9++O+Hj737w6EJzVLlb2n3BXTqhJqK6NQll4vv/Ch2I4kghv8Lw4V4DVCaB8UodG5qSJVpQATZBnM2jt2P/UfNB+L82h6hYefqpqD84mIJr6C1rfSeaciv8uJfM4PFZFZQctk8+bOLdqwkg==" Apr 30 22:31:13 volumio go-librespot[4491]: time="2025-04-30T22:31:13Z" level=info msg="connected to ap-gew4.spotify.com:4070" Apr 30 22:31:13 volumio go-librespot[4491]: time="2025-04-30T22:31:13Z" level=debug msg="completed keyexchange" Apr 30 22:31:13 volumio go-librespot[4491]: time="2025-04-30T22:31:13Z" level=debug msg="completed challenge" Apr 30 22:31:13 volumio go-librespot[4491]: time="2025-04-30T22:31:13Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 30 22:31:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 30 22:31:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 30 22:31:14 volumio volumio[862]: info: Initializing connection to go-librespot Websocket Apr 30 22:31:14 volumio volumio[862]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 30 22:31:15 volumio volumio[862]: info: CoreCommandRouter::volumioGetState Apr 30 22:31:15 volumio volumio[862]: info: CorePlayQueue::getTrack 0 Apr 30 22:31:16 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 30 22:31:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2673. Apr 30 22:31:16 volumio systemd[1]: Stopped go-librespot Daemon. Apr 30 22:31:17 volumio systemd[1]: Started go-librespot Daemon. Apr 30 22:31:17 volumio go-librespot[4511]: Librespot-go daemon starting... Apr 30 22:31:17 volumio go-librespot[4511]: time="2025-04-30T22:31:17Z" level=info msg="generated new device id: 66a0f2460cf3ec34ea8468841a6ba75614cc0318" Apr 30 22:31:17 volumio go-librespot[4511]: time="2025-04-30T22:31:17Z" level=debug msg="stored credentials found for rrx4tvu533kv6l5jtlxq0bnr3" Apr 30 22:31:17 volumio go-librespot[4511]: time="2025-04-30T22:31:17Z" 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]" Apr 30 22:31:17 volumio go-librespot[4511]: time="2025-04-30T22:31:17Z" 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]" Apr 30 22:31:17 volumio go-librespot[4511]: time="2025-04-30T22:31:17Z" 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]" Apr 30 22:31:17 volumio go-librespot[4511]: time="2025-04-30T22:31:17Z" level=debug msg="zeroconf server listening on port 33101" Apr 30 22:31:17 volumio go-librespot[4511]: time="2025-04-30T22:31:17Z" level=debug msg="obtained new client token: AADeQ/XPhb6J2d9OpX2eTeW8XQ1ieCHKsh+jPrPZTJH0tNeTeA18AwHzec2uJnBvzoS9IC1+cP5javvRm2EFbKWtbWdQZ+Tc739CU7GGOgSbA+lMOo9BBwys1sWrDGsu/o5jhjvWzN9g4J248YkqSgEsN19lwcM0XG1VY0BKC/1LRkpZrdABB3T3jTqjFUnH9SuA5XOp4ezZsD7qBoSZB+m8Y7XVCzAC587RxREZDXrQgOXG621Fg1iduiI+" Apr 30 22:31:17 volumio go-librespot[4511]: time="2025-04-30T22:31:17Z" 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" Apr 30 22:31:17 volumio go-librespot[4511]: time="2025-04-30T22:31:17Z" level=info msg="connected to ap-gew4.spotify.com:443" Apr 30 22:31:17 volumio go-librespot[4511]: time="2025-04-30T22:31:17Z" level=debug msg="completed keyexchange" Apr 30 22:31:17 volumio go-librespot[4511]: time="2025-04-30T22:31:17Z" level=debug msg="completed challenge" Apr 30 22:31:17 volumio go-librespot[4511]: time="2025-04-30T22:31:17Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 30 22:31:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 30 22:31:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 30 22:31:18 volumio volumio[862]: info: Initializing connection to go-librespot Websocket Apr 30 22:31:18 volumio volumio[862]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 30 22:31:20 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 30 22:31:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2674. Apr 30 22:31:20 volumio systemd[1]: Stopped go-librespot Daemon. Apr 30 22:31:20 volumio systemd[1]: Started go-librespot Daemon. Apr 30 22:31:20 volumio go-librespot[4522]: Librespot-go daemon starting... Apr 30 22:31:21 volumio go-librespot[4522]: time="2025-04-30T22:31:21Z" level=info msg="generated new device id: ebd755abbd3b2e39d3e9646b08061a920acd0c60" Apr 30 22:31:21 volumio volumio[862]: info: Initializing connection to go-librespot Websocket Apr 30 22:31:21 volumio go-librespot[4522]: time="2025-04-30T22:31:21Z" level=debug msg="stored credentials found for rrx4tvu533kv6l5jtlxq0bnr3" Apr 30 22:31:21 volumio go-librespot[4522]: time="2025-04-30T22:31:21Z" level=debug msg="new websocket client" Apr 30 22:31:21 volumio volumio[862]: info: Connection to go-librespot Websocket established Apr 30 22:31:21 volumio go-librespot[4522]: time="2025-04-30T22:31:21Z" 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]" Apr 30 22:31:21 volumio go-librespot[4522]: time="2025-04-30T22:31:21Z" 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]" Apr 30 22:31:21 volumio go-librespot[4522]: time="2025-04-30T22:31:21Z" 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]" Apr 30 22:31:21 volumio go-librespot[4522]: time="2025-04-30T22:31:21Z" level=debug msg="zeroconf server listening on port 34193" Apr 30 22:31:21 volumio go-librespot[4522]: time="2025-04-30T22:31:21Z" level=debug msg="obtained new client token: AADjd5bQy2dnUW0EjzNiyI2s/zGlqy5WcJRtUlUsLvGfe1wYo21AygcIruB07FzTi7Hsjaf5atLh5OVhgHYrDEIxiiMFhlNg5mWUxgWATBifOjDFr3p9C4hgGiPqUJwJXqBHhfJbj9leVuIptDR7bPVT9cOrBSinFOVdmsw9AfEyry/uALJRbjENOTyVY6w8sDN6NyaAS0FLTK1iQ1zwwzAf/RaBcrAxd7YSHVK6zvQ5m7fiQfvNWcSfYA==" Apr 30 22:31:21 volumio go-librespot[4522]: time="2025-04-30T22:31:21Z" level=info msg="connected to ap-gew4.spotify.com:4070" Apr 30 22:31:21 volumio go-librespot[4522]: time="2025-04-30T22:31:21Z" level=debug msg="completed keyexchange" Apr 30 22:31:21 volumio go-librespot[4522]: time="2025-04-30T22:31:21Z" level=debug msg="completed challenge" Apr 30 22:31:21 volumio go-librespot[4522]: time="2025-04-30T22:31:21Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 30 22:31:21 volumio volumio[862]: info: Connection to go-librespot Websocket closed Apr 30 22:31:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 30 22:31:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 30 22:31:24 volumio volumio[862]: info: Getting Spotify volume Apr 30 22:31:24 volumio volumio[862]: (node:862) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 30 22:31:24 volumio volumio[862]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 30 22:31:24 volumio volumio[862]: (node:862) 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: 309) Apr 30 22:31:24 volumio volumio[862]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Apr 30 22:31:24 volumio volumio[862]: info: CoreCommandRouter::volumioGetState Apr 30 22:31:24 volumio volumio[862]: info: CorePlayQueue::getTrack 0 Apr 30 22:31:24 volumio volumio[862]: info: Initializing connection to go-librespot Websocket Apr 30 22:31:24 volumio volumio[862]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 30 22:31:24 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 30 22:31:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2675. Apr 30 22:31:24 volumio systemd[1]: Stopped go-librespot Daemon. Apr 30 22:31:24 volumio systemd[1]: Started go-librespot Daemon. Apr 30 22:31:24 volumio go-librespot[4544]: Librespot-go daemon starting... Apr 30 22:31:25 volumio go-librespot[4544]: time="2025-04-30T22:31:25Z" level=info msg="generated new device id: 22483cb4fc0bc8900c0687bbd987878b29f81c13" Apr 30 22:31:25 volumio go-librespot[4544]: time="2025-04-30T22:31:25Z" level=debug msg="stored credentials found for rrx4tvu533kv6l5jtlxq0bnr3" Apr 30 22:31:25 volumio go-librespot[4544]: time="2025-04-30T22:31:25Z" 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]" Apr 30 22:31:25 volumio go-librespot[4544]: time="2025-04-30T22:31:25Z" 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]" Apr 30 22:31:25 volumio go-librespot[4544]: time="2025-04-30T22:31:25Z" 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]" Apr 30 22:31:25 volumio go-librespot[4544]: time="2025-04-30T22:31:25Z" level=debug msg="zeroconf server listening on port 46111" Apr 30 22:31:25 volumio go-librespot[4544]: time="2025-04-30T22:31:25Z" level=debug msg="obtained new client token: AAB3VRFlu8uGhHiDVooB95zl+3chHQUYTUDLIXsSTA3NIdUoonJ5L29iiclICmy7cvPhx1lHG9mf1qn7HMqGG7bsMWJejSKS4jZ/jqx9LADwF3j1fq2hJ6c5lSZq9uNt5Kk9U8rM6+mfdoJ0CFaEOyjTJhyNWFhyb8++tZTCPSy3cZrk+WEQ53bPCcSj5uostwUjKabOFh6INBuH8Q0JG0JkqgUQvBA/cm/iEOIsYHBPN9I+HWKZxFhAqQ==" Apr 30 22:31:25 volumio go-librespot[4544]: time="2025-04-30T22:31:25Z" level=info msg="connected to ap-gew4.spotify.com:4070" Apr 30 22:31:25 volumio go-librespot[4544]: time="2025-04-30T22:31:25Z" level=debug msg="completed keyexchange" Apr 30 22:31:25 volumio go-librespot[4544]: time="2025-04-30T22:31:25Z" level=debug msg="completed challenge" Apr 30 22:31:25 volumio go-librespot[4544]: time="2025-04-30T22:31:25Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 30 22:31:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 30 22:31:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 30 22:31:25 volumio volumio[862]: info: CoreCommandRouter::volumioGetState Apr 30 22:31:25 volumio volumio[862]: info: CorePlayQueue::getTrack 0 Apr 30 22:31:25 volumio volumio[862]: info: Listing playlists Apr 30 22:31:25 volumio volumio[862]: info: Listing playlists Apr 30 22:31:27 volumio volumio[862]: info: Initializing connection to go-librespot Websocket Apr 30 22:31:27 volumio volumio[862]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 30 22:31:28 volumio volumio[862]: error: error Apr 30 22:31:28 volumio volumio[862]: error: error Apr 30 22:31:28 volumio volumio[862]: error: error Apr 30 22:31:28 volumio volumio[862]: error: error Apr 30 22:31:28 volumio volumio[862]: error: error Apr 30 22:31:28 volumio volumio[862]: error: error Apr 30 22:31:28 volumio volumio[862]: error: error Apr 30 22:31:28 volumio volumio[862]: error: error Apr 30 22:31:28 volumio volumio[862]: error: error Apr 30 22:31:28 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 30 22:31:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2676. Apr 30 22:31:28 volumio systemd[1]: Stopped go-librespot Daemon. Apr 30 22:31:29 volumio systemd[1]: Started go-librespot Daemon. Apr 30 22:31:29 volumio go-librespot[4603]: Librespot-go daemon starting... Apr 30 22:31:29 volumio go-librespot[4603]: time="2025-04-30T22:31:29Z" level=info msg="generated new device id: 8075f946e007acc46ba8f7334dfebbad1904de63" Apr 30 22:31:29 volumio go-librespot[4603]: time="2025-04-30T22:31:29Z" level=debug msg="stored credentials found for rrx4tvu533kv6l5jtlxq0bnr3" Apr 30 22:31:29 volumio go-librespot[4603]: time="2025-04-30T22:31:29Z" 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]" Apr 30 22:31:29 volumio go-librespot[4603]: time="2025-04-30T22:31:29Z" 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]" Apr 30 22:31:29 volumio go-librespot[4603]: time="2025-04-30T22:31:29Z" 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]" Apr 30 22:31:29 volumio go-librespot[4603]: time="2025-04-30T22:31:29Z" level=debug msg="zeroconf server listening on port 43917" Apr 30 22:31:29 volumio go-librespot[4603]: time="2025-04-30T22:31:29Z" level=debug msg="obtained new client token: AAD5bkWLRa1qgLmK2ZcVZMH0rzBu82J8NA3ynDUR3wSByavqvOxCUzR5EbgrckRHvR8f86GZKT9wonUWI2YzACGLSA/cbgoN1dfx5HQ55d2kN4FMPsyX3aCLhqyoyaerxp4U/z1dq2tFbFrO/9bSL/R7Sge1fcEPPargHP6pn4UAnAf4jk0Lx9jw1dqom97qEEpQqtTr3btWgUTlahksMzJwcc73KJj9omFZR7U/ET5CIwj0PEWmJXk3eQdh" Apr 30 22:31:29 volumio go-librespot[4603]: time="2025-04-30T22:31:29Z" level=info msg="connected to ap-gew4.spotify.com:4070" Apr 30 22:31:29 volumio go-librespot[4603]: time="2025-04-30T22:31:29Z" level=debug msg="completed keyexchange" Apr 30 22:31:29 volumio volumio[862]: info: CoreCommandRouter::volumioGetState Apr 30 22:31:29 volumio volumio[862]: info: CorePlayQueue::getTrack 0 Apr 30 22:31:29 volumio go-librespot[4603]: time="2025-04-30T22:31:29Z" level=debug msg="completed challenge" Apr 30 22:31:29 volumio sudo[4612]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 30 22:31:29 volumio sudo[4612]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 30 22:31:29 volumio sudo[4612]: pam_unix(sudo:session): session closed for user root Apr 30 22:31:29 volumio go-librespot[4603]: time="2025-04-30T22:31:29Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 30 22:31:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 30 22:31:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 30 22:31:29 volumio sudo[4615]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 30 22:31:29 volumio sudo[4615]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 30 22:31:29 volumio sudo[4615]: pam_unix(sudo:session): session closed for user root Apr 30 22:31:29 volumio volumio[862]: verbose: New Socket.io Connection to 192.168.178.20 from 192.168.178.101 UA: Mozilla/5.0 (Linux; Android 15; SM-S916B Build/AP3A.240905.015.A2; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/135.0.7049.111 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Apr 30 22:31:30 volumio volumio[862]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 30 22:31:30 volumio sudo[4618]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 30 22:31:30 volumio sudo[4618]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 30 22:31:30 volumio sudo[4618]: pam_unix(sudo:session): session closed for user root Apr 30 22:31:30 volumio volumio[862]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Apr 30 22:31:30 volumio sudo[4621]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 30 22:31:30 volumio sudo[4621]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 30 22:31:30 volumio sudo[4621]: pam_unix(sudo:session): session closed for user root Apr 30 22:31:30 volumio volumio[862]: verbose: New Socket.io Connection to 192.168.178.20 from 192.168.178.101 UA: Mozilla/5.0 (Linux; Android 15; SM-S916B Build/AP3A.240905.015.A2; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/135.0.7049.111 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Apr 30 22:31:30 volumio volumio[862]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 30 22:31:30 volumio volumio[862]: info: CoreCommandRouter::volumioGetVisibleSources Apr 30 22:31:30 volumio volumio[862]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 30 22:31:30 volumio volumio[862]: info: CoreCommandRouter::volumioGetState Apr 30 22:31:30 volumio volumio[862]: info: CorePlayQueue::getTrack 0 Apr 30 22:31:30 volumio volumio[862]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 30 22:31:30 volumio volumio[862]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 30 22:31:30 volumio volumio[862]: info: Received Get System Info Apr 30 22:31:30 volumio volumio[862]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 30 22:31:30 volumio volumio[862]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 30 22:31:30 volumio volumio[862]: info: Discovery: Getting this device information Apr 30 22:31:30 volumio volumio[862]: info: CoreCommandRouter::volumioGetState Apr 30 22:31:30 volumio volumio[862]: info: CorePlayQueue::getTrack 0 Apr 30 22:31:30 volumio volumio[862]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 30 22:31:30 volumio volumio[862]: info: CoreCommandRouter::volumioGetState Apr 30 22:31:30 volumio volumio[862]: info: CorePlayQueue::getTrack 0 Apr 30 22:31:30 volumio volumio[862]: info: Listing playlists Apr 30 22:31:30 volumio volumio[862]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Apr 30 22:31:30 volumio volumio[862]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 30 22:31:30 volumio volumio[862]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 30 22:31:30 volumio volumio[862]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Apr 30 22:31:30 volumio volumio[862]: info: Initializing connection to go-librespot Websocket Apr 30 22:31:30 volumio volumio[862]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 30 22:31:31 volumio volumio[862]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Apr 30 22:31:32 volumio volumio[862]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 30 22:31:32 volumio volumio[862]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 30 22:31:32 volumio volumio[862]: info: Discovery: Getting this device information Apr 30 22:31:32 volumio volumio[862]: info: CoreCommandRouter::volumioGetState Apr 30 22:31:32 volumio volumio[862]: info: CorePlayQueue::getTrack 0 Apr 30 22:31:32 volumio volumio[862]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 30 22:31:32 volumio volumio[862]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 30 22:31:32 volumio volumio[862]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Apr 30 22:31:32 volumio volumio[862]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 30 22:31:32 volumio volumio[862]: info: Received Get System Info Apr 30 22:31:32 volumio volumio[862]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 30 22:31:32 volumio volumio[862]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 30 22:31:32 volumio volumio[862]: info: Discovery: Getting this device information Apr 30 22:31:32 volumio volumio[862]: info: CoreCommandRouter::volumioGetState Apr 30 22:31:32 volumio volumio[862]: info: CorePlayQueue::getTrack 0 Apr 30 22:31:32 volumio volumio[862]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 30 22:31:32 volumio volumio[862]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 30 22:31:32 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 30 22:31:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2677. Apr 30 22:31:32 volumio systemd[1]: Stopped go-librespot Daemon. Apr 30 22:31:32 volumio systemd[1]: Started go-librespot Daemon. Apr 30 22:31:32 volumio go-librespot[4638]: Librespot-go daemon starting... Apr 30 22:31:33 volumio go-librespot[4638]: time="2025-04-30T22:31:33Z" level=info msg="generated new device id: eecbc4fff1c0889ea462277e408c11e7f89bffee" Apr 30 22:31:33 volumio go-librespot[4638]: time="2025-04-30T22:31:33Z" level=debug msg="stored credentials found for rrx4tvu533kv6l5jtlxq0bnr3" Apr 30 22:31:33 volumio go-librespot[4638]: time="2025-04-30T22:31:33Z" 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]" Apr 30 22:31:33 volumio go-librespot[4638]: time="2025-04-30T22:31:33Z" 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]" Apr 30 22:31:33 volumio go-librespot[4638]: time="2025-04-30T22:31:33Z" 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]" Apr 30 22:31:33 volumio go-librespot[4638]: time="2025-04-30T22:31:33Z" level=debug msg="zeroconf server listening on port 37265" Apr 30 22:31:33 volumio volumio[862]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 30 22:31:33 volumio volumio[862]: info: Received Get System Info Apr 30 22:31:33 volumio volumio[862]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 30 22:31:33 volumio volumio[862]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 30 22:31:33 volumio volumio[862]: info: Discovery: Getting this device information Apr 30 22:31:33 volumio volumio[862]: info: CoreCommandRouter::volumioGetState Apr 30 22:31:33 volumio volumio[862]: info: CorePlayQueue::getTrack 0 Apr 30 22:31:33 volumio volumio[862]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 30 22:31:33 volumio go-librespot[4638]: time="2025-04-30T22:31:33Z" level=debug msg="obtained new client token: AADkoQRkkCgjyhV5RxrW3uU9GPRGIFG3YmiAj6l458p1yIfGIUGv3oCdxUldOhlbq7SCwlkfHh7fEwdLfypwetF1D8VpTQlv2PkygHTByt7j1+0ZSNR6YvKYj1Hky0my/ABsh99CPqkxmn594euOykDAdyou+EA31fhwDHA3mSPnYm9nG85a23r83MTSbAU6uEZNyZnWFq//VCybLnixRAt5NbdGCbaaO1JsXuD0Jr01++JuCeGekdN14w==" Apr 30 22:31:33 volumio go-librespot[4638]: time="2025-04-30T22:31:33Z" level=info msg="connected to ap-gew4.spotify.com:4070" Apr 30 22:31:33 volumio go-librespot[4638]: time="2025-04-30T22:31:33Z" level=debug msg="completed keyexchange" Apr 30 22:31:33 volumio go-librespot[4638]: time="2025-04-30T22:31:33Z" level=debug msg="completed challenge" Apr 30 22:31:33 volumio volumio[862]: info: Initializing connection to go-librespot Websocket Apr 30 22:31:33 volumio go-librespot[4638]: time="2025-04-30T22:31:33Z" level=debug msg="new websocket client" Apr 30 22:31:33 volumio volumio[862]: info: Connection to go-librespot Websocket established Apr 30 22:31:33 volumio go-librespot[4638]: time="2025-04-30T22:31:33Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 30 22:31:33 volumio volumio[862]: info: Connection to go-librespot Websocket closed Apr 30 22:31:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 30 22:31:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 30 22:31:35 volumio volumio[862]: info: CoreCommandRouter::volumioGetState Apr 30 22:31:35 volumio volumio[862]: info: CorePlayQueue::getTrack 0 Apr 30 22:31:36 volumio volumio[862]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/fusiondsp/volumio/buster/armhf Apr 30 22:31:36 volumio volumio[862]: info: Getting Spotify volume Apr 30 22:31:36 volumio volumio[862]: info: Initializing connection to go-librespot Websocket Apr 30 22:31:36 volumio volumio[862]: (node:862) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 30 22:31:36 volumio volumio[862]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 30 22:31:36 volumio volumio[862]: (node:862) 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: 310) Apr 30 22:31:36 volumio volumio[862]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 30 22:31:36 volumio volumio[862]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Apr 30 22:31:36 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 30 22:31:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2678. Apr 30 22:31:36 volumio systemd[1]: Stopped go-librespot Daemon. Apr 30 22:31:36 volumio volumio[862]: info: CoreCommandRouter::volumioGetState Apr 30 22:31:36 volumio volumio[862]: info: CorePlayQueue::getTrack 0 Apr 30 22:31:37 volumio go-librespot[4659]: Librespot-go daemon starting... Apr 30 22:31:37 volumio systemd[1]: Started go-librespot Daemon. Apr 30 22:31:37 volumio go-librespot[4659]: time="2025-04-30T22:31:37Z" level=info msg="generated new device id: 00f698af67b2969cc540883a8c4b9af8b159dd47" Apr 30 22:31:37 volumio go-librespot[4659]: time="2025-04-30T22:31:37Z" level=debug msg="stored credentials found for rrx4tvu533kv6l5jtlxq0bnr3" Apr 30 22:31:37 volumio go-librespot[4659]: time="2025-04-30T22:31:37Z" 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]" Apr 30 22:31:37 volumio go-librespot[4659]: time="2025-04-30T22:31:37Z" 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]" Apr 30 22:31:37 volumio go-librespot[4659]: time="2025-04-30T22:31:37Z" 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]" Apr 30 22:31:37 volumio go-librespot[4659]: time="2025-04-30T22:31:37Z" level=debug msg="zeroconf server listening on port 34389" Apr 30 22:31:37 volumio go-librespot[4659]: time="2025-04-30T22:31:37Z" level=debug msg="obtained new client token: AACqN2jODNV9Jim482L9ASaEqL0o8jaPrniB8rKgBMY6lreO7tnHWCyUAzEn8/m7KXiQCfxsX+UYaOSN3AW4JcTCeDGb7zswNkAOG1n18ioKqq+2kooR4qHX6L4PsJflIFeeDLWJzVHNFr3mB8qDDqEiVJvrlAUMArT8Ic9cVqyE05T4bpLxgChTlsqPzX0+/deVF1qu/f+b7ge5tH0Sxaibm+Ax6291d5tC9dwGFYPOGMgHhIK489Hh1JD4" Apr 30 22:31:37 volumio go-librespot[4659]: time="2025-04-30T22:31:37Z" level=info msg="connected to ap-gew4.spotify.com:4070" Apr 30 22:31:37 volumio go-librespot[4659]: time="2025-04-30T22:31:37Z" level=debug msg="completed keyexchange" Apr 30 22:31:37 volumio go-librespot[4659]: time="2025-04-30T22:31:37Z" level=debug msg="completed challenge" Apr 30 22:31:37 volumio go-librespot[4659]: time="2025-04-30T22:31:37Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 30 22:31:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 30 22:31:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 30 22:31:38 volumio volumio[862]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/fusiondsp/volumio/buster/armhf Apr 30 22:31:38 volumio volumio[862]: info: FusionDsp - Stopping FusionDsp service Apr 30 22:31:38 volumio volumio[862]: info: camilladsp stopping service pid 1340... Apr 30 22:31:38 volumio volumio[862]: info: camilladsp service terminated, instance 1 Apr 30 22:31:39 volumio sudo[4674]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop fusiondsp.service Apr 30 22:31:39 volumio sudo[4674]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 30 22:31:39 volumio systemd[1]: Stopping FusionDsp Daemon... Apr 30 22:31:39 volumio volumio[1348]: Backend configuration: Apr 30 22:31:39 volumio volumio[1348]: active_config: /data/configuration/audio_interface/fusiondsp/camilladsp.yml Apr 30 22:31:39 volumio volumio[1348]: active_config_txt: null Apr 30 22:31:39 volumio volumio[1348]: camilla_host: 127.0.0.1 Apr 30 22:31:39 volumio volumio[1348]: camilla_port: 9876 Apr 30 22:31:39 volumio volumio[1348]: coeff_dir: /data/INTERNAL/FusionDsp/filters Apr 30 22:31:39 volumio volumio[1348]: config_dir: /data/configuration/audio_interface/fusiondsp Apr 30 22:31:39 volumio volumio[1348]: default_config: /data/configuration/audio_interface/fusiondsp/camilladsp.yml Apr 30 22:31:39 volumio volumio[1348]: log_file: /tmp/camilladsp.log Apr 30 22:31:39 volumio volumio[1348]: on_get_active_config: null Apr 30 22:31:39 volumio volumio[1348]: on_set_active_config: null Apr 30 22:31:39 volumio volumio[1348]: port: 5011 Apr 30 22:31:39 volumio volumio[1348]: supported_capture_types: null Apr 30 22:31:39 volumio volumio[1348]: supported_playback_types: null Apr 30 22:31:39 volumio volumio[1348]: update_config_symlink: false Apr 30 22:31:39 volumio volumio[1348]: update_config_txt: false Apr 30 22:31:39 volumio volumio[1348]: ======== Running on http://0.0.0.0:5011 ======== Apr 30 22:31:39 volumio volumio[1348]: (Press CTRL+C to quit) Apr 30 22:31:39 volumio systemd[1]: fusiondsp.service: Succeeded. Apr 30 22:31:39 volumio systemd[1]: Stopped FusionDsp Daemon. Apr 30 22:31:39 volumio volumio[862]: info: Check plugin dependencies Apr 30 22:31:39 volumio sudo[4674]: pam_unix(sudo:session): session closed for user root Apr 30 22:31:39 volumio volumio[862]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 30 22:31:39 volumio volumio[862]: info: Rename folder Apr 30 22:31:39 volumio volumio[862]: info: FusionDsp - Reporting Fusion DSP Disabled Apr 30 22:31:39 volumio volumio[862]: info: Removing fusiondspeq DSP Signal Path Element Apr 30 22:31:39 volumio volumio[862]: info: Folder /tmp/downloaded_plugin.zip removed Apr 30 22:31:39 volumio volumio[862]: info: Move to category Apr 30 22:31:39 volumio volumio[862]: info: Initializing connection to go-librespot Websocket Apr 30 22:31:39 volumio volumio[862]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 30 22:31:40 volumio volumio[862]: info: Checking if install.sh is present Apr 30 22:31:40 volumio volumio[862]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Apr 30 22:31:40 volumio volumio[862]: info: Executing install.sh Apr 30 22:31:40 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 30 22:31:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2679. Apr 30 22:31:40 volumio systemd[1]: Stopped go-librespot Daemon. Apr 30 22:31:41 volumio sudo[4690]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sh /data/plugins/audio_interface/fusiondsp/install.sh Apr 30 22:31:41 volumio sudo[4690]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 30 22:31:41 volumio systemd[1]: Started go-librespot Daemon. Apr 30 22:31:41 volumio volumio[862]: info: creating filters folder and copying demo filters Apr 30 22:31:41 volumio go-librespot[4691]: Librespot-go daemon starting... Apr 30 22:31:41 volumio go-librespot[4691]: time="2025-04-30T22:31:41Z" level=info msg="generated new device id: 1e28e3b9fa076c89af71ab65d2884e60f077bc0b" Apr 30 22:31:41 volumio go-librespot[4691]: time="2025-04-30T22:31:41Z" level=debug msg="stored credentials found for rrx4tvu533kv6l5jtlxq0bnr3" Apr 30 22:31:41 volumio volumio[862]: info: copying demo flters Apr 30 22:31:41 volumio go-librespot[4691]: time="2025-04-30T22:31:41Z" 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]" Apr 30 22:31:41 volumio go-librespot[4691]: time="2025-04-30T22:31:41Z" 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]" Apr 30 22:31:41 volumio go-librespot[4691]: time="2025-04-30T22:31:41Z" 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]" Apr 30 22:31:41 volumio go-librespot[4691]: time="2025-04-30T22:31:41Z" level=debug msg="zeroconf server listening on port 36089" Apr 30 22:31:41 volumio go-librespot[4691]: time="2025-04-30T22:31:41Z" level=debug msg="obtained new client token: AABMbnHTAMei7jMMVim2/mw9npUo1OgjpkiSIt/jBAA3+xHWimpwQf19pOKzQKmxGh3zaVJNYD92jnfw5SijGQEhpFZf1ivSBlA8yWGhL1tZbbihd2acvbXxs7+BMe0MLXL45PSqLqFA6UEMYkJptOzFbPHubQoKkna04yb3262HovFGX3omwHawAlmr/RjR4FKqoBsM2zgQwj2KtEPxaTz8aggqg5MMJrqfTeE8EvL+69f2byFiHZYG5ROy" Apr 30 22:31:41 volumio go-librespot[4691]: time="2025-04-30T22:31:41Z" level=info msg="connected to ap-gew4.spotify.com:4070" Apr 30 22:31:41 volumio go-librespot[4691]: time="2025-04-30T22:31:41Z" level=debug msg="completed keyexchange" Apr 30 22:31:41 volumio volumio[862]: info: ./presets/ Apr 30 22:31:41 volumio volumio[862]: info: ./presets/2XEQ15/ Apr 30 22:31:41 volumio volumio[862]: info: ./presets/2XEQ15/.Bass-FusionDsp.json Apr 30 22:31:41 volumio volumio[862]: info: ./presets/2XEQ15/.Soundtrack-FusionDsp.json Apr 30 22:31:41 volumio volumio[862]: info: ./presets/2XEQ15/.Classic-FusionDsp.json Apr 30 22:31:41 volumio volumio[862]: info: ./presets/2XEQ15/.Voice-FusionDsp.json Apr 30 22:31:41 volumio volumio[862]: info: ./presets/2XEQ15/.Rock-FusionDsp.json Apr 30 22:31:41 volumio volumio[862]: info: ./presets/PEQ/ Apr 30 22:31:41 volumio volumio[862]: info: ./presets/convfir/ Apr 30 22:31:41 volumio volumio[862]: info: ./presets/convfir/kef.json Apr 30 22:31:41 volumio volumio[862]: info: ./presets/convfir/test.json Apr 30 22:31:41 volumio volumio[862]: info: ./presets/EQ15/ Apr 30 22:31:41 volumio volumio[862]: info: ./presets/EQ15/.Bass-FusionDsp.json Apr 30 22:31:41 volumio volumio[862]: info: ./presets/EQ15/.Soundtrack-FusionDsp.json Apr 30 22:31:41 volumio volumio[862]: info: ./presets/EQ15/.Classic-FusionDsp.json Apr 30 22:31:41 volumio volumio[862]: info: ./presets/EQ15/.Voice-FusionDsp.json Apr 30 22:31:41 volumio volumio[862]: info: ./presets/EQ15/.Rock-FusionDsp.json Apr 30 22:31:41 volumio volumio[862]: info: Installing/fusiondsp dependencies Apr 30 22:31:41 volumio sudo[4723]: root : TTY=unknown ; PWD=/data/plugins/audio_interface/fusiondsp ; USER=root ; COMMAND=/usr/bin/apt update Apr 30 22:31:41 volumio sudo[4723]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 30 22:31:41 volumio volumio[862]: info: Get:1 http://raspbian.raspberrypi.org/raspbian buster InRelease [15.0 kB] Apr 30 22:31:41 volumio go-librespot[4691]: time="2025-04-30T22:31:41Z" level=debug msg="completed challenge" Apr 30 22:31:41 volumio volumio[862]: info: Get:2 http://archive.raspberrypi.org/debian buster InRelease [54.2 kB] Apr 30 22:31:41 volumio go-librespot[4691]: time="2025-04-30T22:31:41Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 30 22:31:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 30 22:31:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 30 22:31:41 volumio volumio[862]: info: Hit:3 https://deb.nodesource.com/node_14.x buster InRelease Apr 30 22:31:42 volumio volumio[862]: info: Get:4 http://archive.raspberrypi.org/debian buster/main armhf Packages [400 kB] Apr 30 22:31:42 volumio volumio[862]: info: Fetched 469 kB in 1s (444 kB/s) Apr 30 22:31:42 volumio volumio[862]: info: Initializing connection to go-librespot Websocket Apr 30 22:31:42 volumio volumio[862]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 30 22:31:45 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 30 22:31:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2680. Apr 30 22:31:45 volumio systemd[1]: Stopped go-librespot Daemon. Apr 30 22:31:45 volumio go-librespot[4940]: Librespot-go daemon starting... Apr 30 22:31:45 volumio systemd[1]: Started go-librespot Daemon. Apr 30 22:31:45 volumio go-librespot[4940]: time="2025-04-30T22:31:45Z" level=info msg="generated new device id: fda3c2a7cf8d3ed9bacc102251c12e3859aa355a" Apr 30 22:31:45 volumio go-librespot[4940]: time="2025-04-30T22:31:45Z" level=debug msg="stored credentials found for rrx4tvu533kv6l5jtlxq0bnr3" Apr 30 22:31:45 volumio go-librespot[4940]: time="2025-04-30T22:31:45Z" 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]" Apr 30 22:31:45 volumio go-librespot[4940]: time="2025-04-30T22:31:45Z" 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]" Apr 30 22:31:45 volumio go-librespot[4940]: time="2025-04-30T22:31:45Z" 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]" Apr 30 22:31:45 volumio go-librespot[4940]: time="2025-04-30T22:31:45Z" level=debug msg="zeroconf server listening on port 41399" Apr 30 22:31:45 volumio go-librespot[4940]: time="2025-04-30T22:31:45Z" level=debug msg="obtained new client token: AABOTuoljkABYye2L6s/JOew8vHnEx545TnOxMrUdgfCMq3WC99E8deNw6JuvfsdXhezbF/VpcHiYCE9647q60MLFeA5ZnYxOycyYrzbfzu5pstldQhaouLO6jtF5joACMSr+b+hGIoChvUYz1JdAbLLOSLED0QmlJQqDnM3EhDy/1kF4rtD9vH3UC9QlC0kkmgfw811u1Oc2oMBDOvpVphs8hhGcva6GsUL+UuxH2WNZ62racW9fUbIjrs0" Apr 30 22:31:45 volumio go-librespot[4940]: time="2025-04-30T22:31:45Z" level=info msg="connected to ap-gew4.spotify.com:4070" Apr 30 22:31:45 volumio go-librespot[4940]: time="2025-04-30T22:31:45Z" level=debug msg="completed keyexchange" Apr 30 22:31:45 volumio volumio[862]: info: CoreCommandRouter::volumioGetState Apr 30 22:31:45 volumio volumio[862]: info: CorePlayQueue::getTrack 0 Apr 30 22:31:45 volumio volumio[862]: info: Listing playlists Apr 30 22:31:45 volumio volumio[862]: info: Listing playlists Apr 30 22:31:45 volumio volumio[862]: info: Initializing connection to go-librespot Websocket Apr 30 22:31:45 volumio go-librespot[4940]: time="2025-04-30T22:31:45Z" level=debug msg="new websocket client" Apr 30 22:31:45 volumio volumio[862]: info: Connection to go-librespot Websocket established Apr 30 22:31:46 volumio go-librespot[4940]: time="2025-04-30T22:31:46Z" level=debug msg="completed challenge" Apr 30 22:31:46 volumio go-librespot[4940]: time="2025-04-30T22:31:46Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 30 22:31:46 volumio volumio[862]: info: Connection to go-librespot Websocket closed Apr 30 22:31:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 30 22:31:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 30 22:31:46 volumio volumio[862]: info: Reading package lists... Apr 30 22:31:47 volumio volumio[862]: info: Building dependency tree... Apr 30 22:31:47 volumio volumio[862]: info: Reading state information... Apr 30 22:31:47 volumio sudo[4723]: pam_unix(sudo:session): session closed for user root Apr 30 22:31:47 volumio volumio[862]: info: 179 packages can be upgraded. Run 'apt list --upgradable' to see them. Apr 30 22:31:47 volumio sudo[4961]: root : TTY=unknown ; PWD=/data/plugins/audio_interface/fusiondsp ; USER=root ; COMMAND=/usr/bin/apt -y install python3-aiohttp python3-pip Apr 30 22:31:47 volumio sudo[4961]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 30 22:31:48 volumio volumio[862]: info: Reading package lists... Apr 30 22:31:48 volumio volumio[862]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 30 22:31:48 volumio volumio[862]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Apr 30 22:31:48 volumio volumio[862]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Apr 30 22:31:48 volumio volumio[862]: info: Received Get System Version Apr 30 22:31:48 volumio volumio[862]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 30 22:31:48 volumio volumio[862]: info: Received Get System Info Apr 30 22:31:48 volumio volumio[862]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 30 22:31:48 volumio volumio[862]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 30 22:31:48 volumio volumio[862]: info: Discovery: Getting this device information Apr 30 22:31:48 volumio volumio[862]: info: CoreCommandRouter::volumioGetState Apr 30 22:31:48 volumio volumio[862]: info: CorePlayQueue::getTrack 0 Apr 30 22:31:48 volumio volumio[862]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 30 22:31:48 volumio volumio[862]: info: Building dependency tree... Apr 30 22:31:48 volumio volumio[862]: info: Reading state information... Apr 30 22:31:48 volumio volumio[862]: info: Getting Spotify volume Apr 30 22:31:48 volumio volumio[862]: (node:862) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 30 22:31:48 volumio volumio[862]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 30 22:31:48 volumio volumio[862]: (node:862) 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: 311) Apr 30 22:31:48 volumio volumio[862]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Apr 30 22:31:48 volumio volumio[862]: info: CoreCommandRouter::volumioGetState Apr 30 22:31:48 volumio volumio[862]: info: CorePlayQueue::getTrack 0 Apr 30 22:31:49 volumio volumio[862]: info: Initializing connection to go-librespot Websocket Apr 30 22:31:49 volumio volumio[862]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 30 22:31:49 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 30 22:31:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2681. Apr 30 22:31:49 volumio systemd[1]: Stopped go-librespot Daemon. Apr 30 22:31:49 volumio volumio[862]: info: python3-aiohttp is already the newest version (3.5.1-1+deb10u1). Apr 30 22:31:49 volumio sudo[4961]: pam_unix(sudo:session): session closed for user root Apr 30 22:31:49 volumio sudo[4966]: root : TTY=unknown ; PWD=/data/plugins/audio_interface/fusiondsp ; USER=root ; COMMAND=/bin/tar -xvf fusiondsp.service.tar -C / Apr 30 22:31:49 volumio volumio[862]: info: python3-pip is already the newest version (18.1-5+rpt1). Apr 30 22:31:49 volumio volumio[862]: info: 0 upgraded, 0 newly installed, 0 to remove and 180 not upgraded. Apr 30 22:31:49 volumio sudo[4966]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 30 22:31:49 volumio go-librespot[4965]: Librespot-go daemon starting... Apr 30 22:31:49 volumio systemd[1]: Started go-librespot Daemon. Apr 30 22:31:49 volumio volumio[862]: info: lib/systemd/system/fusiondsp.service Apr 30 22:31:49 volumio sudo[4966]: pam_unix(sudo:session): session closed for user root Apr 30 22:31:49 volumio go-librespot[4965]: time="2025-04-30T22:31:49Z" level=info msg="generated new device id: a009da283c95fac233c98a91ae5021e4fd00e445" Apr 30 22:31:49 volumio go-librespot[4965]: time="2025-04-30T22:31:49Z" level=debug msg="stored credentials found for rrx4tvu533kv6l5jtlxq0bnr3" Apr 30 22:31:49 volumio go-librespot[4965]: time="2025-04-30T22:31:49Z" 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]" Apr 30 22:31:49 volumio go-librespot[4965]: time="2025-04-30T22:31:49Z" 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]" Apr 30 22:31:49 volumio go-librespot[4965]: time="2025-04-30T22:31:49Z" 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]" Apr 30 22:31:49 volumio go-librespot[4965]: time="2025-04-30T22:31:49Z" level=debug msg="zeroconf server listening on port 39977" Apr 30 22:31:49 volumio go-librespot[4965]: time="2025-04-30T22:31:49Z" level=debug msg="obtained new client token: AABVGfjoQ3pTdQIRhO/F8WLu2ktU0Me2URstMRlJmZcWdT4AoAxEC9PDdSwLHuOwK6dNJ2wNaQFtxGMidKG9dA2UYVQTUVktt6NgNHEs+AKXeWRM+yFJMucW7a47hNjQJLUprWAH2f9AOAFlBDOj1gQBHrpEQXCWo5TU7I1P/tbWYlVCC6OMq8NF/R35XLdW6oGUjj8JKdhwPn3YEBJ+fNy/lOxYVemaVAr89/bpOjXNw7fCI3UPciM6oaH/" Apr 30 22:31:49 volumio go-librespot[4965]: time="2025-04-30T22:31:49Z" level=info msg="connected to ap-gew4.spotify.com:4070" Apr 30 22:31:49 volumio go-librespot[4965]: time="2025-04-30T22:31:49Z" level=debug msg="completed keyexchange" Apr 30 22:31:50 volumio go-librespot[4965]: time="2025-04-30T22:31:50Z" level=debug msg="completed challenge" Apr 30 22:31:50 volumio go-librespot[4965]: time="2025-04-30T22:31:50Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 30 22:31:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 30 22:31:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 30 22:31:51 volumio volumio[862]: info: MiniUnz 1.01b, demo of zLib + Unz package written by Gilles Vollant Apr 30 22:31:51 volumio sudo[4977]: root : TTY=unknown ; PWD=/data/plugins/audio_interface/fusiondsp ; USER=root ; COMMAND=/bin/chown -R volumio cgui Apr 30 22:31:51 volumio sudo[4977]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 30 22:31:51 volumio volumio[862]: info: more info at http://www.winimage.com/zLibDll/unzip.html Apr 30 22:31:51 volumio volumio[862]: info: Apr 30 22:31:51 volumio volumio[862]: info: cgui-1.0.0.zip opened Apr 30 22:31:51 volumio volumio[862]: info: creating directory: cgui/ Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/LICENSE.txt Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/README.md Apr 30 22:31:51 volumio volumio[862]: info: creating directory: cgui/build/ Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/build/robots.txt Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/build/logo512.png Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/build/asset-manifest.json Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/build/index.html Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/build/.put_statics_here Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/build/favicon.ico Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/build/logo192.png Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/build/.xdp-css-variables-1.css-PvrWoX Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/build/manifest.json Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/build/css-variables.css Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/build/precache-manifest.76db5aad1647230454f47b1e22783b54.js Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/build/service-worker.js Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/build/precache-manifest.5e6c675b70ef6a3fe73d0209febfe347.js Apr 30 22:31:51 volumio volumio[862]: info: creating directory: cgui/build/static/ Apr 30 22:31:51 volumio volumio[862]: info: creating directory: cgui/build/static/css/ Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/build/static/css/main.d51d005e.chunk.css Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/build/static/css/main.d51d005e.chunk.css.map Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/build/static/css/2.975d6916.chunk.css.map Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/build/static/css/main.56bdf14e.chunk.css Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/build/static/css/main.56bdf14e.chunk.css.map Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/build/static/css/main.1503f6cd.css.map Apr 30 22:31:51 volumio sudo[4977]: pam_unix(sudo:session): session closed for user root Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/build/static/css/2.a4c7e7cf.chunk.css.map Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/build/static/css/main.1503f6cd.css Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/build/static/css/2.975d6916.chunk.css Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/build/static/css/2.a4c7e7cf.chunk.css Apr 30 22:31:51 volumio volumio[862]: info: creating directory: cgui/build/static/media/ Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/build/static/media/camilladsp.95719842.svg Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/build/static/media/camilladsp.4767ea4ad3510467418b818dc677a87e.svg Apr 30 22:31:51 volumio volumio[862]: info: creating directory: cgui/build/static/js/ Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/build/static/js/2.fd49ece5.chunk.js.map Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/build/static/js/main.71e11955.js Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/build/static/js/runtime-main.422581ec.js Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/build/static/js/2.fd49ece5.chunk.js Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/build/static/js/2.c1b9df8b.chunk.js.LICENSE.txt Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/build/static/js/main.61bb6809.chunk.js Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/build/static/js/main.61bb6809.chunk.js.map Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/build/static/js/2.c1b9df8b.chunk.js Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/build/static/js/main.1b3ac690.chunk.js.map Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/build/static/js/main.71e11955.js.LICENSE.txt Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/build/static/js/main.71e11955.js.map Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/build/static/js/runtime-main.422581ec.js.map Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/build/static/js/main.1b3ac690.chunk.js Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/build/static/js/2.c1b9df8b.chunk.js.map Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/build/static/js/2.fd49ece5.chunk.js.LICENSE.txt Apr 30 22:31:51 volumio sudo[4979]: root : TTY=unknown ; PWD=/data/plugins/audio_interface/fusiondsp ; USER=root ; COMMAND=/bin/chgrp -R volumio cgui Apr 30 22:31:51 volumio sudo[4979]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 30 22:31:51 volumio sudo[4979]: pam_unix(sudo:session): session closed for user root Apr 30 22:31:51 volumio volumio[862]: info: creating directory: cgui/config/ Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/config/camillagui.yml Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/config/.xdp-css-variables-1.css-ppBDuX Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/config/gui-config.yml Apr 30 22:31:51 volumio volumio[862]: info: creating directory: cgui/backend/ Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/backend/filters_test.py Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/backend/version.py Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/backend/filters.py Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/backend/settings.py Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/backend/views.py Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/backend/filterdefaults.py Apr 30 22:31:51 volumio sudo[4981]: root : TTY=unknown ; PWD=/data/plugins/audio_interface/fusiondsp ; USER=root ; COMMAND=/bin/rm cgui-1.0.0.zip Apr 30 22:31:51 volumio sudo[4981]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/backend/__init__.py Apr 30 22:31:51 volumio volumio[862]: info: creating directory: cgui/backend/__pycache__/ Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/backend/__pycache__/filterdefaults.cpython-37.pyc Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/backend/__pycache__/views.cpython-37.pyc Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/backend/__pycache__/settings.cpython-37.pyc Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/backend/__pycache__/__init__.cpython-37.pyc Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/backend/__pycache__/routes.cpython-37.pyc Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/backend/__pycache__/filemanagement.cpython-37.pyc Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/backend/__pycache__/filters.cpython-37.pyc Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/backend/__pycache__/version.cpython-37.pyc Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/backend/routes.py Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/backend/filemanagement.py Apr 30 22:31:51 volumio volumio[862]: info: extracting: cgui/main.py Apr 30 22:31:51 volumio sudo[4981]: pam_unix(sudo:session): session closed for user root Apr 30 22:31:52 volumio volumio[862]: info: Initializing connection to go-librespot Websocket Apr 30 22:31:52 volumio volumio[862]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 30 22:31:53 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 30 22:31:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2682. Apr 30 22:31:53 volumio systemd[1]: Stopped go-librespot Daemon. Apr 30 22:31:53 volumio systemd[1]: Started go-librespot Daemon. Apr 30 22:31:53 volumio go-librespot[5000]: Librespot-go daemon starting... Apr 30 22:31:53 volumio go-librespot[5000]: time="2025-04-30T22:31:53Z" level=info msg="generated new device id: 39ffc481b9e22275cb86d7218d7ca3a8bcde2139" Apr 30 22:31:53 volumio go-librespot[5000]: time="2025-04-30T22:31:53Z" level=debug msg="stored credentials found for rrx4tvu533kv6l5jtlxq0bnr3" Apr 30 22:31:53 volumio go-librespot[5000]: time="2025-04-30T22:31:53Z" 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]" Apr 30 22:31:53 volumio go-librespot[5000]: time="2025-04-30T22:31:53Z" 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]" Apr 30 22:31:53 volumio go-librespot[5000]: time="2025-04-30T22:31:53Z" 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]" Apr 30 22:31:53 volumio go-librespot[5000]: time="2025-04-30T22:31:53Z" level=debug msg="zeroconf server listening on port 37513" Apr 30 22:31:53 volumio go-librespot[5000]: time="2025-04-30T22:31:53Z" level=debug msg="obtained new client token: AABZfWEc2SoJmJoeBgV9JFOs75ACN7Zzii+Due8/Z+HFseYXsCSBYmawIPMmABUAAdlwtAx90PpaZSuhdOL/8duBjbXtY0TiyMTLlkZDp3O6e4Id6aCn5N1haCR9Ej9C+cpyYSpF9MAvCxcFfR0OPG0P8Qv30EB8YF5zAGL1lLdlnsYcKpa3SQ4OrhxukGARQByuaVIT+Lbxhpj0w8vO1twJYRsVwcQzN8phYvZD53lo6PJm3Frr5xSi7f5h" Apr 30 22:31:53 volumio go-librespot[5000]: time="2025-04-30T22:31:53Z" level=info msg="connected to ap-gew4.spotify.com:4070" Apr 30 22:31:53 volumio go-librespot[5000]: time="2025-04-30T22:31:53Z" level=debug msg="completed keyexchange" Apr 30 22:31:54 volumio go-librespot[5000]: time="2025-04-30T22:31:54Z" level=debug msg="completed challenge" Apr 30 22:31:54 volumio go-librespot[5000]: time="2025-04-30T22:31:54Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 30 22:31:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 30 22:31:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 30 22:31:55 volumio volumio[862]: info: Initializing connection to go-librespot Websocket Apr 30 22:31:55 volumio volumio[862]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 30 22:31:55 volumio volumio[862]: info: Looking in indexes: https://pypi.org/simple, https://www.piwheels.org/simple Apr 30 22:31:55 volumio volumio[862]: info: Collecting git+https://github.com/HEnquist/pycamilladsp.git@v1.0.0 Apr 30 22:31:55 volumio volumio[862]: info: Cloning https://github.com/HEnquist/pycamilladsp.git (to revision v1.0.0) to /tmp/pip-req-build-0sm8s7o9 Apr 30 22:31:55 volumio volumio[862]: info: CoreCommandRouter::volumioGetState Apr 30 22:31:55 volumio volumio[862]: info: CorePlayQueue::getTrack 0 Apr 30 22:31:57 volumio volumio[862]: info: Requirement already satisfied (use --upgrade to upgrade): camilladsp==1.0.0 from git+https://github.com/HEnquist/pycamilladsp.git@v1.0.0 in /usr/local/lib/python3.7/dist-packages Apr 30 22:31:57 volumio volumio[862]: info: Requirement already satisfied: PyYAML in /usr/local/lib/python3.7/dist-packages (from camilladsp==1.0.0) (6.0) Apr 30 22:31:57 volumio volumio[862]: info: Requirement already satisfied: websocket_client in /usr/local/lib/python3.7/dist-packages (from camilladsp==1.0.0) (1.4.2) Apr 30 22:31:57 volumio volumio[862]: info: Building wheels for collected packages: camilladsp Apr 30 22:31:57 volumio volumio[862]: info: Running setup.py bdist_wheel for camilladsp: started Apr 30 22:31:57 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 30 22:31:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2683. Apr 30 22:31:57 volumio systemd[1]: Stopped go-librespot Daemon. Apr 30 22:31:57 volumio go-librespot[5043]: Librespot-go daemon starting... Apr 30 22:31:57 volumio systemd[1]: Started go-librespot Daemon. Apr 30 22:31:57 volumio go-librespot[5043]: time="2025-04-30T22:31:57Z" level=info msg="generated new device id: a62c7197932c7ef38a08ddcee558585f085ca8c1" Apr 30 22:31:57 volumio go-librespot[5043]: time="2025-04-30T22:31:57Z" level=debug msg="stored credentials found for rrx4tvu533kv6l5jtlxq0bnr3" Apr 30 22:31:57 volumio go-librespot[5043]: time="2025-04-30T22:31:57Z" 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]" Apr 30 22:31:57 volumio go-librespot[5043]: time="2025-04-30T22:31:57Z" 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]" Apr 30 22:31:57 volumio go-librespot[5043]: time="2025-04-30T22:31:57Z" 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]" Apr 30 22:31:57 volumio go-librespot[5043]: time="2025-04-30T22:31:57Z" level=debug msg="zeroconf server listening on port 39231" Apr 30 22:31:58 volumio go-librespot[5043]: time="2025-04-30T22:31:58Z" level=debug msg="obtained new client token: AACdaU+/w81KfgxS1VDH12s0PkKcY2Wo7gAx6OBqM/8WhSzNY0BUyjUclYL1JF3sSKnC/XJUmrXOTW5n6qnoU2HfSGnAxMXo1ohAf7+mAyCby1kK9VwI1GzgRQp5g5YzSH57llsvEJX+C8CtaplIL3G6XKbkF2OVmVF022UyQ0uvXikLOgNAyzKI5RhtnOg7jsoyWwtaa4mlQ7REwS5HX+ddU7oHaK6gvbGnG9fKoR2uyrLQZKCW9O7uFg==" Apr 30 22:31:58 volumio go-librespot[5043]: time="2025-04-30T22:31:58Z" level=info msg="connected to ap-gew4.spotify.com:4070" Apr 30 22:31:58 volumio go-librespot[5043]: time="2025-04-30T22:31:58Z" level=debug msg="completed keyexchange" Apr 30 22:31:58 volumio volumio[862]: info: Initializing connection to go-librespot Websocket Apr 30 22:31:58 volumio go-librespot[5043]: time="2025-04-30T22:31:58Z" level=debug msg="new websocket client" Apr 30 22:31:58 volumio volumio[862]: info: Connection to go-librespot Websocket established Apr 30 22:31:58 volumio volumio[862]: info: Running setup.py bdist_wheel for camilladsp: finished with status 'done' Apr 30 22:31:58 volumio volumio[862]: info: Stored in directory: /tmp/pip-ephem-wheel-cache-w5jnkn34/wheels/ca/47/7d/ee36beb671f74869a8e2ecb2c3fd4a28c1b7488a9c78e442b6 Apr 30 22:31:58 volumio volumio[862]: info: Successfully built camilladsp Apr 30 22:31:58 volumio go-librespot[5043]: time="2025-04-30T22:31:58Z" level=debug msg="completed challenge" Apr 30 22:31:58 volumio go-librespot[5043]: time="2025-04-30T22:31:58Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 30 22:31:58 volumio volumio[862]: info: Connection to go-librespot Websocket closed Apr 30 22:31:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 30 22:31:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 30 22:32:01 volumio volumio[862]: info: Getting Spotify volume Apr 30 22:32:01 volumio volumio[862]: (node:862) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 30 22:32:01 volumio volumio[862]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 30 22:32:01 volumio volumio[862]: (node:862) 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: 312) Apr 30 22:32:01 volumio volumio[862]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Apr 30 22:32:01 volumio volumio[862]: info: CoreCommandRouter::volumioGetState Apr 30 22:32:01 volumio volumio[862]: info: CorePlayQueue::getTrack 0 Apr 30 22:32:01 volumio volumio[862]: info: Initializing connection to go-librespot Websocket Apr 30 22:32:01 volumio volumio[862]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 30 22:32:01 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 30 22:32:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2684. Apr 30 22:32:01 volumio systemd[1]: Stopped go-librespot Daemon. Apr 30 22:32:01 volumio go-librespot[5055]: Librespot-go daemon starting... Apr 30 22:32:01 volumio systemd[1]: Started go-librespot Daemon. Apr 30 22:32:01 volumio go-librespot[5055]: time="2025-04-30T22:32:01Z" level=info msg="generated new device id: ae9671cc55bb13baa5e27dcb9ef3186f7f391ef1" Apr 30 22:32:01 volumio go-librespot[5055]: time="2025-04-30T22:32:01Z" level=debug msg="stored credentials found for rrx4tvu533kv6l5jtlxq0bnr3" Apr 30 22:32:01 volumio go-librespot[5055]: time="2025-04-30T22:32:01Z" 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]" Apr 30 22:32:01 volumio go-librespot[5055]: time="2025-04-30T22:32:01Z" 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]" Apr 30 22:32:01 volumio go-librespot[5055]: time="2025-04-30T22:32:01Z" 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]" Apr 30 22:32:01 volumio go-librespot[5055]: time="2025-04-30T22:32:01Z" level=debug msg="zeroconf server listening on port 45801" Apr 30 22:32:02 volumio go-librespot[5055]: time="2025-04-30T22:32:02Z" level=debug msg="obtained new client token: AAC87LXV4/CwyphwQwWDmD3cDHMIplEVw1UEro1et4Lc/Gsf9Lz5ETw6816llQmozsLwYwtk5DPg7g7RxqsmUEMTAGyM9ML3TMpLe/E7MzVyZk17SCKeu6Jr8oeRanGl8U9Y+61lpwRqa2pMrtHgVHZxRfwaTtP1h6cIZk9xm33AL9xpOjsDnciYftXvVOamamwcDiAOPoIzrk4rSqChySdl31JmiGu3w3/FB2i1aOqiGoa76XVosZz5lA==" Apr 30 22:32:02 volumio go-librespot[5055]: time="2025-04-30T22:32:02Z" level=info msg="connected to ap-gew4.spotify.com:4070" Apr 30 22:32:02 volumio go-librespot[5055]: time="2025-04-30T22:32:02Z" level=debug msg="completed keyexchange" Apr 30 22:32:02 volumio volumio[862]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 30 22:32:02 volumio volumio[862]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 30 22:32:02 volumio volumio[862]: info: Discovery: Getting this device information Apr 30 22:32:02 volumio volumio[862]: info: CoreCommandRouter::volumioGetState Apr 30 22:32:02 volumio volumio[862]: info: CorePlayQueue::getTrack 0 Apr 30 22:32:02 volumio volumio[862]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 30 22:32:02 volumio volumio[862]: info: Looking in indexes: https://pypi.org/simple, https://www.piwheels.org/simple Apr 30 22:32:02 volumio volumio[862]: info: Collecting git+https://github.com/HEnquist/pycamilladsp-plot.git@v1.0.2 Apr 30 22:32:02 volumio volumio[862]: info: Cloning https://github.com/HEnquist/pycamilladsp-plot.git (to revision v1.0.2) to /tmp/pip-req-build-r3l_neaa Apr 30 22:32:02 volumio go-librespot[5055]: time="2025-04-30T22:32:02Z" level=debug msg="completed challenge" Apr 30 22:32:02 volumio go-librespot[5055]: time="2025-04-30T22:32:02Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 30 22:32:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 30 22:32:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 30 22:32:03 volumio volumio[862]: info: Requirement already satisfied (use --upgrade to upgrade): camilladsp-plot==1.0.2 from git+https://github.com/HEnquist/pycamilladsp-plot.git@v1.0.2 in /usr/local/lib/python3.7/dist-packages Apr 30 22:32:03 volumio volumio[862]: info: Requirement already satisfied: PyYAML in /usr/local/lib/python3.7/dist-packages (from camilladsp-plot==1.0.2) (6.0) Apr 30 22:32:03 volumio volumio[862]: info: Requirement already satisfied: jsonschema in /usr/local/lib/python3.7/dist-packages (from camilladsp-plot==1.0.2) (4.17.3) Apr 30 22:32:03 volumio volumio[862]: info: Requirement already satisfied: pyrsistent!=0.17.0,!=0.17.1,!=0.17.2,>=0.14.0 in /usr/local/lib/python3.7/dist-packages (from jsonschema->camilladsp-plot==1.0.2) (0.19.3) Apr 30 22:32:03 volumio volumio[862]: info: Requirement already satisfied: pkgutil-resolve-name>=1.3.10; python_version < "3.9" in /usr/local/lib/python3.7/dist-packages (from jsonschema->camilladsp-plot==1.0.2) (1.3.10) Apr 30 22:32:03 volumio volumio[862]: info: Requirement already satisfied: attrs>=17.4.0 in /usr/lib/python3/dist-packages (from jsonschema->camilladsp-plot==1.0.2) (18.2.0) Apr 30 22:32:03 volumio volumio[862]: info: Requirement already satisfied: importlib-metadata; python_version < "3.8" in /usr/local/lib/python3.7/dist-packages (from jsonschema->camilladsp-plot==1.0.2) (6.0.0) Apr 30 22:32:03 volumio volumio[862]: info: Requirement already satisfied: typing-extensions; python_version < "3.8" in /usr/local/lib/python3.7/dist-packages (from jsonschema->camilladsp-plot==1.0.2) (4.4.0) Apr 30 22:32:03 volumio volumio[862]: info: Requirement already satisfied: importlib-resources>=1.4.0; python_version < "3.9" in /usr/local/lib/python3.7/dist-packages (from jsonschema->camilladsp-plot==1.0.2) (5.10.2) Apr 30 22:32:03 volumio volumio[862]: info: Requirement already satisfied: zipp>=0.5 in /usr/local/lib/python3.7/dist-packages (from importlib-metadata; python_version < "3.8"->jsonschema->camilladsp-plot==1.0.2) (3.11.0) Apr 30 22:32:04 volumio volumio[862]: info: Building wheels for collected packages: camilladsp-plot Apr 30 22:32:04 volumio volumio[862]: info: Running setup.py bdist_wheel for camilladsp-plot: started Apr 30 22:32:04 volumio volumio[862]: info: Initializing connection to go-librespot Websocket Apr 30 22:32:04 volumio volumio[862]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 30 22:32:04 volumio volumio[862]: info: Running setup.py bdist_wheel for camilladsp-plot: finished with status 'done' Apr 30 22:32:04 volumio volumio[862]: info: Stored in directory: /tmp/pip-ephem-wheel-cache-zi4pf9h8/wheels/11/e1/43/8275af2f537d569c7097d202b4955f9aec629859be39dab2e9 Apr 30 22:32:04 volumio volumio[862]: info: Successfully built camilladsp-plot Apr 30 22:32:05 volumio volumio[862]: info: copying hw detection script Apr 30 22:32:05 volumio volumio[862]: info: Detected cpu architecture as armv7l Apr 30 22:32:05 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 30 22:32:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2685. Apr 30 22:32:05 volumio systemd[1]: Stopped go-librespot Daemon. Apr 30 22:32:05 volumio systemd[1]: Started go-librespot Daemon. Apr 30 22:32:05 volumio go-librespot[5104]: Librespot-go daemon starting... Apr 30 22:32:05 volumio go-librespot[5104]: time="2025-04-30T22:32:05Z" level=info msg="generated new device id: 817043bc047e1e21a53499a733450cbea034aec1" Apr 30 22:32:05 volumio go-librespot[5104]: time="2025-04-30T22:32:05Z" level=debug msg="stored credentials found for rrx4tvu533kv6l5jtlxq0bnr3" Apr 30 22:32:05 volumio volumio[862]: info: CoreCommandRouter::volumioGetState Apr 30 22:32:05 volumio volumio[862]: info: CorePlayQueue::getTrack 0 Apr 30 22:32:05 volumio volumio[862]: info: Listing playlists Apr 30 22:32:05 volumio volumio[862]: info: Listing playlists Apr 30 22:32:05 volumio go-librespot[5104]: time="2025-04-30T22:32:05Z" 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]" Apr 30 22:32:05 volumio go-librespot[5104]: time="2025-04-30T22:32:05Z" 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]" Apr 30 22:32:05 volumio go-librespot[5104]: time="2025-04-30T22:32:05Z" 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]" Apr 30 22:32:05 volumio go-librespot[5104]: time="2025-04-30T22:32:05Z" level=debug msg="zeroconf server listening on port 42175" Apr 30 22:32:06 volumio go-librespot[5104]: time="2025-04-30T22:32:06Z" level=debug msg="obtained new client token: AAD0Pvd+eN7aYb6vp3lgNnMw13Gdybs/qBslMbrzlZgppH/gGrIvyLt7PTIUjLfd0tQb3JroN9P0mvAVQ+o847pbK3SZHTZtsLfINwbdFVzQIZfLCnW4knLkVHQa8XINsnb8Jb7v/mnwBBGGxorRKPgKl+qBcsx4oygjNn/8mJDg56KDZfLjWKitsVPBHxkXhSKs2zSFPck9kkoDUFK4uohTAUrsCX2iDAlrW5aOss0ULVIWJpHkWgI=" Apr 30 22:32:06 volumio go-librespot[5104]: time="2025-04-30T22:32:06Z" level=info msg="connected to ap-gew4.spotify.com:4070" Apr 30 22:32:06 volumio go-librespot[5104]: time="2025-04-30T22:32:06Z" level=debug msg="completed keyexchange" Apr 30 22:32:06 volumio sudo[5131]: root : TTY=unknown ; PWD=/tmp ; USER=root ; COMMAND=/bin/cp /data/plugins/audio_interface/fusiondsp/c/hw_params_arm /data/plugins/audio_interface/fusiondsp/hw_params Apr 30 22:32:06 volumio sudo[5131]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 30 22:32:06 volumio sudo[5131]: pam_unix(sudo:session): session closed for user root Apr 30 22:32:06 volumio sudo[5133]: root : TTY=unknown ; PWD=/tmp ; USER=root ; COMMAND=/bin/chmod +x /data/plugins/audio_interface/fusiondsp/hw_params Apr 30 22:32:06 volumio sudo[5133]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 30 22:32:06 volumio sudo[5133]: pam_unix(sudo:session): session closed for user root Apr 30 22:32:06 volumio sudo[5135]: root : TTY=unknown ; PWD=/tmp ; USER=root ; COMMAND=/usr/bin/apt-get -y install drc Apr 30 22:32:06 volumio sudo[5135]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 30 22:32:06 volumio go-librespot[5104]: time="2025-04-30T22:32:06Z" level=debug msg="completed challenge" Apr 30 22:32:06 volumio go-librespot[5104]: time="2025-04-30T22:32:06Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 30 22:32:06 volumio volumio[862]: info: Reading package lists... Apr 30 22:32:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 30 22:32:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 30 22:32:07 volumio volumio[862]: info: Building dependency tree... Apr 30 22:32:07 volumio volumio[862]: info: Reading state information... Apr 30 22:32:07 volumio volumio[862]: info: Initializing connection to go-librespot Websocket Apr 30 22:32:07 volumio volumio[862]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 30 22:32:08 volumio volumio[862]: info: drc is already the newest version (3.2.2~dfsg0-2). Apr 30 22:32:08 volumio volumio[862]: info: 0 upgraded, 0 newly installed, 0 to remove and 180 not upgraded. Apr 30 22:32:08 volumio sudo[5135]: pam_unix(sudo:session): session closed for user root Apr 30 22:32:08 volumio sudo[4690]: pam_unix(sudo:session): session closed for user root Apr 30 22:32:08 volumio volumio[862]: info: Install script completed Apr 30 22:32:08 volumio volumio[862]: info: Done installing plugin. Apr 30 22:32:08 volumio volumio[862]: info: Enabling plugin fusiondsp Apr 30 22:32:08 volumio volumio[862]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 30 22:32:08 volumio volumio[862]: info: [{"prettyName":"FusionDsp","name":"fusiondsp","category":"audio_interface","version":"1.0.61","icon":"fa-sliders fa-rotate-90","isManuallyInstalled":true,"enabled":true,"active":false},{"prettyName":"miniDLNA","name":"minidlna","category":"music_service","version":"3.1.12","icon":"fa-share-alt","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"Spotify","name":"spop","category":"music_service","version":"4.1.1","icon":"fa-spotify","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"YouTube2","name":"youtube2","category":"music_service","version":"1.3.1","icon":"fa-youtube-play","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"Backup & Restore Data","name":"backup_restore","category":"system_controller","version":"0.7.4","icon":"fa-floppy-o","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"Music Services Shield","name":"music_services_shield","category":"system_hardware","version":"1.3.1","icon":"fa-shield","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"System information","name":"Systeminfo","category":"user_interface","version":"3.0.6","icon":"fa-info-circle","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"Now Playing","name":"now_playing","category":"user_interface","version":"0.7.5","icon":"fa-play-circle","isManuallyInstalled":false,"enabled":true,"active":true}] Apr 30 22:32:08 volumio volumio[862]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Apr 30 22:32:08 volumio volumio[862]: Plugin install end detected on script Apr 30 22:32:08 volumio volumio[862]: info: Folder /tmp/plugins removed Apr 30 22:32:08 volumio volumio[862]: info: Folder /tmp/downloaded_plugin.zip removed Apr 30 22:32:08 volumio volumio[862]: info: Folder /data/temp removed Apr 30 22:32:08 volumio volumio[862]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 30 22:32:09 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 30 22:32:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2686. Apr 30 22:32:09 volumio systemd[1]: Stopped go-librespot Daemon. Apr 30 22:32:09 volumio systemd[1]: Started go-librespot Daemon. Apr 30 22:32:09 volumio go-librespot[5139]: Librespot-go daemon starting... Apr 30 22:32:09 volumio go-librespot[5139]: time="2025-04-30T22:32:09Z" level=info msg="generated new device id: 45a7bc46ff4efeccaf6c21c9943f75a30f145867" Apr 30 22:32:09 volumio go-librespot[5139]: time="2025-04-30T22:32:09Z" level=debug msg="stored credentials found for rrx4tvu533kv6l5jtlxq0bnr3" Apr 30 22:32:09 volumio go-librespot[5139]: time="2025-04-30T22:32:09Z" 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]" Apr 30 22:32:09 volumio go-librespot[5139]: time="2025-04-30T22:32:09Z" 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]" Apr 30 22:32:09 volumio go-librespot[5139]: time="2025-04-30T22:32:09Z" 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]" Apr 30 22:32:09 volumio go-librespot[5139]: time="2025-04-30T22:32:09Z" level=debug msg="zeroconf server listening on port 35207" Apr 30 22:32:10 volumio go-librespot[5139]: time="2025-04-30T22:32:10Z" level=debug msg="obtained new client token: AAA9pRhPuxckf/YKvSl37e/mhjbDKFDYNCshxbc/Yy3CXBLGsGx/1n7sCd9/9XMgrVmKkPDm3qB22CjnDJX0tCEwMdce6S8951VoRduFw+a5ZeQkRCPIZjpQcfoFJunZrJV01hp8tFX+9aw8v4kGSAjGOS4TsWHK0AGKQUkNrKhT5+DqWD8nUR4C8ncZOxH2E/XipVHSMn9LT68o0epekH7JgR45OkjXlisMLy3cBfDi0JxRkeEAZboOaQ==" Apr 30 22:32:10 volumio go-librespot[5139]: time="2025-04-30T22:32:10Z" level=info msg="connected to ap-gew4.spotify.com:4070" Apr 30 22:32:10 volumio go-librespot[5139]: time="2025-04-30T22:32:10Z" level=debug msg="completed keyexchange" Apr 30 22:32:10 volumio go-librespot[5139]: time="2025-04-30T22:32:10Z" level=debug msg="completed challenge" Apr 30 22:32:10 volumio go-librespot[5139]: time="2025-04-30T22:32:10Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 30 22:32:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 30 22:32:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 30 22:32:10 volumio volumio[862]: info: Initializing connection to go-librespot Websocket Apr 30 22:32:10 volumio volumio[862]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 30 22:32:13 volumio volumio[862]: info: Initializing connection to go-librespot Websocket Apr 30 22:32:13 volumio volumio[862]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 30 22:32:13 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 30 22:32:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2687. Apr 30 22:32:13 volumio systemd[1]: Stopped go-librespot Daemon. Apr 30 22:32:13 volumio systemd[1]: Started go-librespot Daemon. Apr 30 22:32:13 volumio go-librespot[5163]: Librespot-go daemon starting... Apr 30 22:32:13 volumio go-librespot[5163]: time="2025-04-30T22:32:13Z" level=info msg="generated new device id: 795cd6aee243671fe76011b336e68a28377f3302" Apr 30 22:32:13 volumio go-librespot[5163]: time="2025-04-30T22:32:13Z" level=debug msg="stored credentials found for rrx4tvu533kv6l5jtlxq0bnr3" Apr 30 22:32:13 volumio go-librespot[5163]: time="2025-04-30T22:32:13Z" 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]" Apr 30 22:32:13 volumio go-librespot[5163]: time="2025-04-30T22:32:13Z" 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]" Apr 30 22:32:13 volumio go-librespot[5163]: time="2025-04-30T22:32:13Z" 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]" Apr 30 22:32:13 volumio go-librespot[5163]: time="2025-04-30T22:32:13Z" level=debug msg="zeroconf server listening on port 41579" Apr 30 22:32:14 volumio go-librespot[5163]: time="2025-04-30T22:32:14Z" level=debug msg="obtained new client token: AACH7Vf7kdlTnhp/Pe2Nw8yQIul6gXXuMkFNJkpClFHm8vuJOp1flNxPpWendAyAV19mKXgOYwqjeM2mdpKrifWqm6UdpzZPe03Fm5AmMVMqTon1T/Zs/OzW8eQWn3N2thamfJm4RxycWPmoTiyAkENOhFpBtXRudddIDNh4iQAIJMahY/LN6uD0v5rSOUIOq8OiHJKGf2Dphq/xXQPq0whpySp0FVv+IggZQab5RZ699QucJ1ZD3fv6EbE5" Apr 30 22:32:14 volumio go-librespot[5163]: time="2025-04-30T22:32:14Z" level=info msg="connected to ap-gew4.spotify.com:4070" Apr 30 22:32:14 volumio go-librespot[5163]: time="2025-04-30T22:32:14Z" level=debug msg="completed keyexchange" Apr 30 22:32:14 volumio go-librespot[5163]: time="2025-04-30T22:32:14Z" level=debug msg="completed challenge" Apr 30 22:32:14 volumio go-librespot[5163]: time="2025-04-30T22:32:14Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 30 22:32:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 30 22:32:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 30 22:32:15 volumio volumio[862]: info: CoreCommandRouter::volumioGetState Apr 30 22:32:15 volumio volumio[862]: info: CorePlayQueue::getTrack 0 Apr 30 22:32:16 volumio volumio[862]: error: error Apr 30 22:32:16 volumio volumio[862]: error: error Apr 30 22:32:16 volumio volumio[862]: error: error Apr 30 22:32:16 volumio volumio[862]: error: error Apr 30 22:32:16 volumio volumio[862]: info: Initializing connection to go-librespot Websocket Apr 30 22:32:16 volumio volumio[862]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 30 22:32:17 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 30 22:32:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2688. Apr 30 22:32:17 volumio systemd[1]: Stopped go-librespot Daemon. Apr 30 22:32:17 volumio systemd[1]: Started go-librespot Daemon. Apr 30 22:32:17 volumio go-librespot[5186]: Librespot-go daemon starting... Apr 30 22:32:17 volumio go-librespot[5186]: time="2025-04-30T22:32:17Z" level=info msg="generated new device id: c632b791c4cf6668b700db7fa8cd593382e17d60" Apr 30 22:32:17 volumio go-librespot[5186]: time="2025-04-30T22:32:17Z" level=debug msg="stored credentials found for rrx4tvu533kv6l5jtlxq0bnr3" Apr 30 22:32:17 volumio go-librespot[5186]: time="2025-04-30T22:32:17Z" 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]" Apr 30 22:32:17 volumio go-librespot[5186]: time="2025-04-30T22:32:17Z" 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]" Apr 30 22:32:17 volumio go-librespot[5186]: time="2025-04-30T22:32:17Z" 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]" Apr 30 22:32:17 volumio go-librespot[5186]: time="2025-04-30T22:32:17Z" level=debug msg="zeroconf server listening on port 37979" Apr 30 22:32:18 volumio go-librespot[5186]: time="2025-04-30T22:32:18Z" level=debug msg="obtained new client token: AADoBJkcbtGlWClRAPSZnCRPPZ3qcebpi99isJSi+e/VmaXqzALZmev2S6yNKSmv0mxnMoWZY96G02HWHtQAODLfF6eA37EdJC8Ne5uJ6y2GD/D/R6ImDwQPDiIPYjqRM3rR8djl8F6J1h/R/4N+Yg9Hw5g7aZ3YgwTDf235jP5m5DigRTJva047/v3pmT0K+t3Ri7bKxDFvQZx1u1uj5EmWrmNw70BOM31S3C5a22Lvzpr8+OT043RXlydt" Apr 30 22:32:18 volumio go-librespot[5186]: time="2025-04-30T22:32:18Z" level=info msg="connected to ap-gew4.spotify.com:4070" Apr 30 22:32:18 volumio go-librespot[5186]: time="2025-04-30T22:32:18Z" level=debug msg="completed keyexchange" Apr 30 22:32:18 volumio go-librespot[5186]: time="2025-04-30T22:32:18Z" level=debug msg="completed challenge" Apr 30 22:32:18 volumio go-librespot[5186]: time="2025-04-30T22:32:18Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 30 22:32:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 30 22:32:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 30 22:32:19 volumio volumio[862]: info: Initializing connection to go-librespot Websocket Apr 30 22:32:19 volumio volumio[862]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 30 22:32:21 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 30 22:32:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2689. Apr 30 22:32:21 volumio systemd[1]: Stopped go-librespot Daemon. Apr 30 22:32:21 volumio systemd[1]: Started go-librespot Daemon. Apr 30 22:32:21 volumio go-librespot[5194]: Librespot-go daemon starting... Apr 30 22:32:21 volumio go-librespot[5194]: time="2025-04-30T22:32:21Z" level=info msg="generated new device id: 989c36dd3746d3d004417ccea4f094e9ad4df36d" Apr 30 22:32:21 volumio go-librespot[5194]: time="2025-04-30T22:32:21Z" level=debug msg="stored credentials found for rrx4tvu533kv6l5jtlxq0bnr3" Apr 30 22:32:21 volumio go-librespot[5194]: time="2025-04-30T22:32:21Z" 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]" Apr 30 22:32:21 volumio go-librespot[5194]: time="2025-04-30T22:32:21Z" 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]" Apr 30 22:32:21 volumio go-librespot[5194]: time="2025-04-30T22:32:21Z" 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]" Apr 30 22:32:21 volumio go-librespot[5194]: time="2025-04-30T22:32:21Z" level=debug msg="zeroconf server listening on port 39581" Apr 30 22:32:22 volumio go-librespot[5194]: time="2025-04-30T22:32:22Z" level=debug msg="obtained new client token: AAC4l3cJgJMZevce+ytmFSN9UeYDnqw1rTQhQNdVE2sBP3J9QZkXcBT6VQJXjiBrZiC9PMwh0rgQbRvrG2FL01gBKpivxIwcE3usU/TAhuUGAZ0b1X42ZSux8B5kf/dz9WNsrKnYyzhA4YBsxcYJJoZgTurDG6ypl8Vn/xr/nv4qFBxgV7/yWlRRNPUNAdxjhsvFY5GnxUJG+VDhHeMh13SBgswBXTXcQcv9wn/SjczUj76Xg0pbeV7hew==" Apr 30 22:32:22 volumio go-librespot[5194]: time="2025-04-30T22:32:22Z" level=info msg="connected to ap-gew4.spotify.com:4070" Apr 30 22:32:22 volumio go-librespot[5194]: time="2025-04-30T22:32:22Z" level=debug msg="completed keyexchange" Apr 30 22:32:22 volumio go-librespot[5194]: time="2025-04-30T22:32:22Z" level=debug msg="completed challenge" Apr 30 22:32:22 volumio go-librespot[5194]: time="2025-04-30T22:32:22Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 30 22:32:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 30 22:32:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 30 22:32:22 volumio volumio[862]: info: Initializing connection to go-librespot Websocket Apr 30 22:32:22 volumio volumio[862]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 30 22:32:25 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 30 22:32:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2690. Apr 30 22:32:25 volumio systemd[1]: Stopped go-librespot Daemon. Apr 30 22:32:25 volumio volumio[862]: info: Initializing connection to go-librespot Websocket Apr 30 22:32:25 volumio volumio[862]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 30 22:32:25 volumio systemd[1]: Started go-librespot Daemon. Apr 30 22:32:25 volumio go-librespot[5215]: Librespot-go daemon starting... Apr 30 22:32:25 volumio go-librespot[5215]: time="2025-04-30T22:32:25Z" level=info msg="generated new device id: f4aebe09321ac3ed8cc3bd3f0b7632dfd67760e9" Apr 30 22:32:25 volumio go-librespot[5215]: time="2025-04-30T22:32:25Z" level=debug msg="stored credentials found for rrx4tvu533kv6l5jtlxq0bnr3" Apr 30 22:32:25 volumio volumio[862]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 30 22:32:25 volumio volumio[862]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Apr 30 22:32:25 volumio volumio[862]: info: CoreCommandRouter::volumioGetState Apr 30 22:32:25 volumio volumio[862]: info: CorePlayQueue::getTrack 0 Apr 30 22:32:25 volumio volumio[862]: info: Listing playlists Apr 30 22:32:25 volumio volumio[862]: info: Listing playlists Apr 30 22:32:25 volumio go-librespot[5215]: time="2025-04-30T22:32:25Z" 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]" Apr 30 22:32:25 volumio go-librespot[5215]: time="2025-04-30T22:32:25Z" 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]" Apr 30 22:32:25 volumio go-librespot[5215]: time="2025-04-30T22:32:25Z" 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]" Apr 30 22:32:25 volumio go-librespot[5215]: time="2025-04-30T22:32:25Z" level=debug msg="zeroconf server listening on port 37641" Apr 30 22:32:26 volumio go-librespot[5215]: time="2025-04-30T22:32:26Z" level=debug msg="obtained new client token: AADbN913hoQuGncaz32rzNLbfW3/26X/UcN1ncH/mfwhqKsoMsWMpiJANCoLU3H18vonohWSc7LNiUNztIzT2fnwJ96ibtKHA3VutKDayrnukur8j1GlTuKq+D6LyjSHEqHJ6QgATzj4m16aKzfndNt/x2jw11kaDTQ3ns26yShu/tF4rzRXq+ggT1KemYyTyauAY1ezu4Tnw99e4Sf6Pxy4nWZd9F+QxOVdINTmRS/GTQaKosdD6fm+dA==" Apr 30 22:32:26 volumio go-librespot[5215]: time="2025-04-30T22:32:26Z" level=info msg="connected to ap-gew4.spotify.com:4070" Apr 30 22:32:26 volumio go-librespot[5215]: time="2025-04-30T22:32:26Z" level=debug msg="completed keyexchange" Apr 30 22:32:26 volumio go-librespot[5215]: time="2025-04-30T22:32:26Z" level=debug msg="completed challenge" Apr 30 22:32:26 volumio go-librespot[5215]: time="2025-04-30T22:32:26Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 30 22:32:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 30 22:32:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 30 22:32:28 volumio volumio[862]: info: Initializing connection to go-librespot Websocket Apr 30 22:32:28 volumio volumio[862]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 30 22:32:29 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 30 22:32:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2691. Apr 30 22:32:29 volumio systemd[1]: Stopped go-librespot Daemon. Apr 30 22:32:29 volumio systemd[1]: Started go-librespot Daemon. Apr 30 22:32:29 volumio go-librespot[5275]: Librespot-go daemon starting... Apr 30 22:32:29 volumio go-librespot[5275]: time="2025-04-30T22:32:29Z" level=info msg="generated new device id: 4ea901143e2c3a00cccd2421fa48ce8f69feb184" Apr 30 22:32:29 volumio go-librespot[5275]: time="2025-04-30T22:32:29Z" level=debug msg="stored credentials found for rrx4tvu533kv6l5jtlxq0bnr3" Apr 30 22:32:29 volumio go-librespot[5275]: time="2025-04-30T22:32:29Z" 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]" Apr 30 22:32:29 volumio go-librespot[5275]: time="2025-04-30T22:32:29Z" 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]" Apr 30 22:32:29 volumio go-librespot[5275]: time="2025-04-30T22:32:29Z" 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]" Apr 30 22:32:29 volumio go-librespot[5275]: time="2025-04-30T22:32:29Z" level=debug msg="zeroconf server listening on port 39369" Apr 30 22:32:30 volumio go-librespot[5275]: time="2025-04-30T22:32:30Z" level=debug msg="obtained new client token: AADYfeBY0d9Pdvi1ZhSw867r6d4Xczu8fIy7UBWetcKoOC8QLf2hiNAqCRhLXvNtPA8jVxdyUOoEyQhqaQJbAp86jXWu9eHMe0QUpN4zoL7J/Y8myHPhKgJDWwDI7W10vv/2sTiMQTCEFVl4wbg7G6C/B318xD8S/L4blT+EEanZyocvcMQJk68HDT6AF53q5YrB9p8alW7I6rjaOJq7XTZcJ6/rlv4r8mhmrOURvXQA+5pP+YJBed9kJg==" Apr 30 22:32:30 volumio go-librespot[5275]: time="2025-04-30T22:32:30Z" level=info msg="connected to ap-gew4.spotify.com:4070" Apr 30 22:32:30 volumio go-librespot[5275]: time="2025-04-30T22:32:30Z" level=debug msg="completed keyexchange" Apr 30 22:32:30 volumio volumio[862]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/fusiondsp/volumio/buster/armhf Apr 30 22:32:30 volumio go-librespot[5275]: time="2025-04-30T22:32:30Z" level=debug msg="completed challenge" Apr 30 22:32:30 volumio go-librespot[5275]: time="2025-04-30T22:32:30Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Apr 30 22:32:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 30 22:32:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 30 22:32:31 volumio volumio[862]: info: Initializing connection to go-librespot Websocket Apr 30 22:32:31 volumio volumio[862]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 30 22:32:32 volumio volumio[862]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/fusiondsp/volumio/buster/armhf Apr 30 22:32:32 volumio volumio[862]: info: FusionDsp - Stopping FusionDsp service Apr 30 22:32:32 volumio volumio[862]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 30 22:32:32 volumio volumio[862]: TypeError: Cannot read property 'stop' of null Apr 30 22:32:32 volumio volumio[862]: at FusionDsp.onStop (/data/plugins/audio_interface/fusiondsp/index.js:109:23) Apr 30 22:32:32 volumio volumio[862]: at PluginManager.stopPlugin (/volumio/app/pluginmanager.js:460:30) Apr 30 22:32:32 volumio volumio[862]: at /volumio/app/pluginmanager.js:956:12 Apr 30 22:32:32 volumio volumio[862]: at ChildProcess.exithandler (child_process.js:299:7) Apr 30 22:32:32 volumio volumio[862]: at ChildProcess.emit (events.js:315:20) Apr 30 22:32:32 volumio volumio[862]: at maybeClose (internal/child_process.js:1048:16) Apr 30 22:32:32 volumio volumio[862]: at Socket. (internal/child_process.js:439:11) Apr 30 22:32:32 volumio volumio[862]: at Socket.emit (events.js:315:20) Apr 30 22:32:32 volumio volumio[862]: at Pipe. (net.js:673:12) Apr 30 22:32:32 volumio volumio[862]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 30 22:32:32 volumio sudo[5298]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-04-30 22:31 Apr 30 22:32:32 volumio sudo[5298]: 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="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="9ab87de061b3649c303da550e73c92d340b0f989" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 24 Apr 2025 09:33:57 AM CEST" VOLUMIO_VERSION="3.804" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="354f95cf0a6c2cbcd57b1aca3179c81c"