-- Logs begin at Fri 2024-03-22 08:13:25 MDT, end at Sat 2025-06-21 14:23:50 MDT. -- Jun 21 14:22:01 minidspshd volumio[688]: info: Getting Spotify volume Jun 21 14:22:01 minidspshd volumio[688]: (node:688) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:22:01 minidspshd volumio[688]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Jun 21 14:22:01 minidspshd volumio[688]: (node:688) 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: 75) Jun 21 14:22:01 minidspshd volumio[688]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 Jun 21 14:22:01 minidspshd volumio[688]: info: CoreCommandRouter::volumioGetState Jun 21 14:22:01 minidspshd volumio[688]: info: CorePlayQueue::getTrack 0 Jun 21 14:22:01 minidspshd volumio[688]: SPOTIFY: RECEIVED VOLUMIO VOLUME 77 Jun 21 14:22:01 minidspshd volumio[688]: info: Initializing connection to go-librespot Websocket Jun 21 14:22:01 minidspshd volumio[688]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:22:01 minidspshd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 21 14:22:01 minidspshd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 230. Jun 21 14:22:01 minidspshd systemd[1]: Stopped go-librespot Daemon. Jun 21 14:22:01 minidspshd systemd[1]: Started go-librespot Daemon. Jun 21 14:22:01 minidspshd go-librespot[4021]: go-librespot daemon starting... Jun 21 14:22:02 minidspshd go-librespot[4021]: time="2025-06-21T14:22:02-06:00" level=info msg="running go-librespot 0.2.0" Jun 21 14:22:02 minidspshd go-librespot[4021]: time="2025-06-21T14:22:02-06:00" level=debug msg="app state loaded" Jun 21 14:22:02 minidspshd go-librespot[4021]: time="2025-06-21T14:22:02-06:00" level=debug msg="stored credentials not found" Jun 21 14:22:02 minidspshd go-librespot[4021]: time="2025-06-21T14:22:02-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 21 14:22:02 minidspshd go-librespot[4021]: time="2025-06-21T14:22:02-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 21 14:22:02 minidspshd go-librespot[4021]: time="2025-06-21T14:22:02-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 21 14:22:02 minidspshd go-librespot[4021]: time="2025-06-21T14:22:02-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 21 14:22:02 minidspshd go-librespot[4021]: time="2025-06-21T14:22:02-06:00" level=info msg="zeroconf server listening on port 38191" Jun 21 14:22:02 minidspshd go-librespot[4021]: time="2025-06-21T14:22:02-06:00" level=debug msg="obtained new client token: AABndiSi0fCsGTtY3FcUYFBElLdiaxMl6q4WoKcjqgSqL86C96ucBbl667ZYcJqwd14xQPvpxEk+xMy5PiDdn8H7P1wHPBzeCXTyTRfvC5Z0rS5CD2ti8GyeyUQVq6L5gejFWs05A3q0vwtF1nRSHk2xFL8HMQOqvAD2YFl9tA++3CCtbtztMdedp615tzIFs02P59U9rlz5/kGvG2yc2nvQXRwo5fd1ghwUwAj4EoVxYCHPAxczvSk=" Jun 21 14:22:02 minidspshd go-librespot[4021]: time="2025-06-21T14:22:02-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jun 21 14:22:02 minidspshd go-librespot[4021]: time="2025-06-21T14:22:02-06:00" level=debug msg="completed keyexchange" Jun 21 14:22:02 minidspshd go-librespot[4021]: time="2025-06-21T14:22:02-06:00" level=debug msg="completed challenge" Jun 21 14:22:02 minidspshd go-librespot[4021]: time="2025-06-21T14:22:02-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 21 14:22:02 minidspshd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 21 14:22:02 minidspshd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 21 14:22:04 minidspshd volumio[688]: info: Initializing connection to go-librespot Websocket Jun 21 14:22:04 minidspshd volumio[688]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:22:05 minidspshd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 21 14:22:05 minidspshd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 231. Jun 21 14:22:05 minidspshd systemd[1]: Stopped go-librespot Daemon. Jun 21 14:22:05 minidspshd systemd[1]: Started go-librespot Daemon. Jun 21 14:22:05 minidspshd go-librespot[4029]: go-librespot daemon starting... Jun 21 14:22:06 minidspshd go-librespot[4029]: time="2025-06-21T14:22:06-06:00" level=info msg="running go-librespot 0.2.0" Jun 21 14:22:06 minidspshd go-librespot[4029]: time="2025-06-21T14:22:06-06:00" level=debug msg="app state loaded" Jun 21 14:22:06 minidspshd go-librespot[4029]: time="2025-06-21T14:22:06-06:00" level=debug msg="stored credentials not found" Jun 21 14:22:06 minidspshd go-librespot[4029]: time="2025-06-21T14:22:06-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 21 14:22:06 minidspshd go-librespot[4029]: time="2025-06-21T14:22:06-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 21 14:22:06 minidspshd go-librespot[4029]: time="2025-06-21T14:22:06-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 21 14:22:06 minidspshd go-librespot[4029]: time="2025-06-21T14:22:06-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 21 14:22:06 minidspshd go-librespot[4029]: time="2025-06-21T14:22:06-06:00" level=info msg="zeroconf server listening on port 32849" Jun 21 14:22:06 minidspshd go-librespot[4029]: time="2025-06-21T14:22:06-06:00" level=debug msg="obtained new client token: AAAKizeBkvhhqrkrjDCTFaap6Oit1iv4nJpW57h9/7ApfzVX1oZxQ5MyTEz3UjDAC9eWCxnnkMsY+vOdoHbTkVHK5hzi2FbTq5niVMYuhRWMk+sfI+49+2QgUuIk9808rXlEY01Rp5fNUCptdAFk8uT5KPUDhZXz/8g2cXU1jINCLqziSUUDvd58tvhcPch/NC6o5l+z4vRwtlH3RizE9qNKcxSaTtIlshEVUFBrKDu9xfLBcOEUHUM=" Jun 21 14:22:06 minidspshd go-librespot[4029]: time="2025-06-21T14:22:06-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jun 21 14:22:06 minidspshd go-librespot[4029]: time="2025-06-21T14:22:06-06:00" level=debug msg="completed keyexchange" Jun 21 14:22:06 minidspshd go-librespot[4029]: time="2025-06-21T14:22:06-06:00" level=debug msg="completed challenge" Jun 21 14:22:06 minidspshd go-librespot[4029]: time="2025-06-21T14:22:06-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 21 14:22:06 minidspshd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 21 14:22:06 minidspshd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 21 14:22:07 minidspshd volumio[688]: info: Initializing connection to go-librespot Websocket Jun 21 14:22:07 minidspshd volumio[688]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:22:09 minidspshd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 21 14:22:09 minidspshd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 232. Jun 21 14:22:09 minidspshd systemd[1]: Stopped go-librespot Daemon. Jun 21 14:22:09 minidspshd systemd[1]: Started go-librespot Daemon. Jun 21 14:22:09 minidspshd go-librespot[4038]: go-librespot daemon starting... Jun 21 14:22:10 minidspshd go-librespot[4038]: time="2025-06-21T14:22:10-06:00" level=info msg="running go-librespot 0.2.0" Jun 21 14:22:10 minidspshd go-librespot[4038]: time="2025-06-21T14:22:10-06:00" level=debug msg="app state loaded" Jun 21 14:22:10 minidspshd go-librespot[4038]: time="2025-06-21T14:22:10-06:00" level=debug msg="stored credentials not found" Jun 21 14:22:10 minidspshd go-librespot[4038]: time="2025-06-21T14:22:10-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 21 14:22:10 minidspshd go-librespot[4038]: time="2025-06-21T14:22:10-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 21 14:22:10 minidspshd go-librespot[4038]: time="2025-06-21T14:22:10-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 21 14:22:10 minidspshd go-librespot[4038]: time="2025-06-21T14:22:10-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 21 14:22:10 minidspshd go-librespot[4038]: time="2025-06-21T14:22:10-06:00" level=info msg="zeroconf server listening on port 43781" Jun 21 14:22:10 minidspshd go-librespot[4038]: time="2025-06-21T14:22:10-06:00" level=debug msg="obtained new client token: AADLcqoo28SmJYRCqLicd7j1h3a9z9r9E7JLXZbteJkwGmPSOKx9xvAAXnaeFYYfW1gBHEzuVBC+tD5pITDVBRM8j6AUsZB+/LhQ71A4G5rr3dTKxSC3vP31lS20ZkSdKwLnysx7Y1U8s50m/U0uZp7EytrPCiHrmS2nMzjJ1tQUeH2RL7nVe/dCoSBSZVBeQzAUPuBAFQf3djsKPYwiRxW/cLYVK1xF8I137xd6+l5ZhExntRJCa8w=" Jun 21 14:22:10 minidspshd go-librespot[4038]: time="2025-06-21T14:22:10-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jun 21 14:22:10 minidspshd volumio[688]: info: Initializing connection to go-librespot Websocket Jun 21 14:22:10 minidspshd go-librespot[4038]: time="2025-06-21T14:22:10-06:00" level=debug msg="new websocket client" Jun 21 14:22:10 minidspshd volumio[688]: info: Connection to go-librespot Websocket established Jun 21 14:22:10 minidspshd go-librespot[4038]: time="2025-06-21T14:22:10-06:00" level=debug msg="completed keyexchange" Jun 21 14:22:10 minidspshd go-librespot[4038]: time="2025-06-21T14:22:10-06:00" level=debug msg="completed challenge" Jun 21 14:22:10 minidspshd go-librespot[4038]: time="2025-06-21T14:22:10-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 21 14:22:10 minidspshd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 21 14:22:10 minidspshd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 21 14:22:10 minidspshd volumio[688]: info: Connection to go-librespot Websocket closed Jun 21 14:22:13 minidspshd volumio[688]: info: Getting Spotify volume Jun 21 14:22:13 minidspshd volumio[688]: (node:688) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:22:13 minidspshd volumio[688]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Jun 21 14:22:13 minidspshd volumio[688]: (node:688) 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: 76) Jun 21 14:22:13 minidspshd volumio[688]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 Jun 21 14:22:13 minidspshd volumio[688]: info: Initializing connection to go-librespot Websocket Jun 21 14:22:14 minidspshd volumio[688]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:22:14 minidspshd volumio[688]: info: CoreCommandRouter::volumioGetState Jun 21 14:22:14 minidspshd volumio[688]: info: CorePlayQueue::getTrack 0 Jun 21 14:22:14 minidspshd volumio[688]: SPOTIFY: RECEIVED VOLUMIO VOLUME 77 Jun 21 14:22:14 minidspshd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 21 14:22:14 minidspshd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 233. Jun 21 14:22:14 minidspshd systemd[1]: Stopped go-librespot Daemon. Jun 21 14:22:14 minidspshd systemd[1]: Started go-librespot Daemon. Jun 21 14:22:14 minidspshd go-librespot[4084]: go-librespot daemon starting... Jun 21 14:22:14 minidspshd go-librespot[4084]: time="2025-06-21T14:22:14-06:00" level=info msg="running go-librespot 0.2.0" Jun 21 14:22:14 minidspshd go-librespot[4084]: time="2025-06-21T14:22:14-06:00" level=debug msg="app state loaded" Jun 21 14:22:14 minidspshd go-librespot[4084]: time="2025-06-21T14:22:14-06:00" level=debug msg="stored credentials not found" Jun 21 14:22:14 minidspshd go-librespot[4084]: time="2025-06-21T14:22:14-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 21 14:22:14 minidspshd go-librespot[4084]: time="2025-06-21T14:22:14-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 21 14:22:14 minidspshd go-librespot[4084]: time="2025-06-21T14:22:14-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 21 14:22:14 minidspshd go-librespot[4084]: time="2025-06-21T14:22:14-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 21 14:22:14 minidspshd go-librespot[4084]: time="2025-06-21T14:22:14-06:00" level=info msg="zeroconf server listening on port 37781" Jun 21 14:22:14 minidspshd go-librespot[4084]: time="2025-06-21T14:22:14-06:00" level=debug msg="obtained new client token: AADDZOncGFhavu/R6B3NLQ/KA56hlR8krioFQYosb8u7X+MDMBcORShjxI1PQYcxFKGRbKR/3vKfZXSaz+p6Z9L3uVxEosJkvOvxEGTDuqVKOts8VHVZjT3+rH/kN1oEgG/5xTvRYxEmdW8k93BJURz+0QRrAXmhMvQb3D2p1uG8EkELeGKNmEtEql/8Pwy8l/d5VzJxfTPb8sjeEUsYnOQzJmk661RRAVh6190HWMuaVp3YWqmXqHw=" Jun 21 14:22:14 minidspshd go-librespot[4084]: time="2025-06-21T14:22:14-06:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused" Jun 21 14:22:15 minidspshd go-librespot[4084]: time="2025-06-21T14:22:15-06:00" level=debug msg="connected to ap-guc3.spotify.com:443" Jun 21 14:22:15 minidspshd go-librespot[4084]: time="2025-06-21T14:22:15-06:00" level=debug msg="completed keyexchange" Jun 21 14:22:15 minidspshd go-librespot[4084]: time="2025-06-21T14:22:15-06:00" level=debug msg="completed challenge" Jun 21 14:22:15 minidspshd go-librespot[4084]: time="2025-06-21T14:22:15-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 21 14:22:15 minidspshd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 21 14:22:15 minidspshd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 21 14:22:17 minidspshd volumio[688]: info: Initializing connection to go-librespot Websocket Jun 21 14:22:17 minidspshd volumio[688]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:22:17 minidspshd sudo[4093]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 21 14:22:17 minidspshd sudo[4093]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 21 14:22:17 minidspshd sudo[4093]: pam_unix(sudo:session): session closed for user root Jun 21 14:22:17 minidspshd sudo[4096]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 21 14:22:17 minidspshd sudo[4096]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 21 14:22:17 minidspshd sudo[4096]: pam_unix(sudo:session): session closed for user root Jun 21 14:22:17 minidspshd volumio[688]: verbose: New Socket.io Connection to 192.168.0.222 from 192.168.0.213 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/137.0.0.0 Safari/537.36 Total Clients: 6 Jun 21 14:22:17 minidspshd sudo[4101]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 21 14:22:17 minidspshd sudo[4101]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 21 14:22:17 minidspshd sudo[4101]: pam_unix(sudo:session): session closed for user root Jun 21 14:22:17 minidspshd sudo[4104]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 21 14:22:17 minidspshd sudo[4104]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 21 14:22:17 minidspshd sudo[4104]: pam_unix(sudo:session): session closed for user root Jun 21 14:22:18 minidspshd volumio[688]: verbose: New Socket.io Connection to 192.168.0.222 from 192.168.0.213 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/137.0.0.0 Safari/537.36 Total Clients: 7 Jun 21 14:22:18 minidspshd volumio[688]: info: CoreCommandRouter::volumioGetState Jun 21 14:22:18 minidspshd volumio[688]: info: CorePlayQueue::getTrack 0 Jun 21 14:22:18 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jun 21 14:22:18 minidspshd volumio[688]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Jun 21 14:22:18 minidspshd volumio[688]: info: CoreCommandRouter::volumioGetVisibleSources Jun 21 14:22:18 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 21 14:22:18 minidspshd volumio[688]: info: Listing playlists Jun 21 14:22:18 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jun 21 14:22:18 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jun 21 14:22:18 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jun 21 14:22:18 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 21 14:22:18 minidspshd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 21 14:22:18 minidspshd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 234. Jun 21 14:22:18 minidspshd systemd[1]: Stopped go-librespot Daemon. Jun 21 14:22:18 minidspshd systemd[1]: Started go-librespot Daemon. Jun 21 14:22:18 minidspshd go-librespot[4108]: go-librespot daemon starting... Jun 21 14:22:19 minidspshd go-librespot[4108]: time="2025-06-21T14:22:19-06:00" level=info msg="running go-librespot 0.2.0" Jun 21 14:22:19 minidspshd go-librespot[4108]: time="2025-06-21T14:22:19-06:00" level=debug msg="app state loaded" Jun 21 14:22:19 minidspshd go-librespot[4108]: time="2025-06-21T14:22:19-06:00" level=debug msg="stored credentials not found" Jun 21 14:22:19 minidspshd go-librespot[4108]: time="2025-06-21T14:22:19-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 21 14:22:19 minidspshd go-librespot[4108]: time="2025-06-21T14:22:19-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 21 14:22:19 minidspshd go-librespot[4108]: time="2025-06-21T14:22:19-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 21 14:22:19 minidspshd go-librespot[4108]: time="2025-06-21T14:22:19-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 21 14:22:19 minidspshd go-librespot[4108]: time="2025-06-21T14:22:19-06:00" level=info msg="zeroconf server listening on port 43771" Jun 21 14:22:19 minidspshd go-librespot[4108]: time="2025-06-21T14:22:19-06:00" level=debug msg="obtained new client token: AAD9x0sua7Qg9f4QUi7TLmtET2SqljYssUx82U/oCsWoaBKpJmQCSad0KbLkFrsfheEwX9Myi4p0Hkc8VnBtiPvBBkI9vKyDFMGG7cvZ04zQfgnvfma+5gZnJNLov+kU44uAX4IHgAgOUgvqTcUSbQesmGDfvvEAODWM1d4JkuQmRRIIe7fJzgUnXgz5JuGs4zwMH8RFZ8MhpQpZgLIEXapJKB13kLk3KhA9UDH/Z9VgCfKUHSFxf+o=" Jun 21 14:22:19 minidspshd go-librespot[4108]: time="2025-06-21T14:22:19-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jun 21 14:22:19 minidspshd go-librespot[4108]: time="2025-06-21T14:22:19-06:00" level=debug msg="completed keyexchange" Jun 21 14:22:19 minidspshd go-librespot[4108]: time="2025-06-21T14:22:19-06:00" level=debug msg="completed challenge" Jun 21 14:22:19 minidspshd go-librespot[4108]: time="2025-06-21T14:22:19-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 21 14:22:19 minidspshd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 21 14:22:19 minidspshd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 21 14:22:20 minidspshd volumio[688]: info: Initializing connection to go-librespot Websocket Jun 21 14:22:20 minidspshd volumio[688]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:22:20 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 21 14:22:20 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 21 14:22:23 minidspshd volumio[688]: info: Initializing connection to go-librespot Websocket Jun 21 14:22:23 minidspshd volumio[688]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:22:23 minidspshd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 21 14:22:23 minidspshd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 235. Jun 21 14:22:23 minidspshd systemd[1]: Stopped go-librespot Daemon. Jun 21 14:22:23 minidspshd systemd[1]: Started go-librespot Daemon. Jun 21 14:22:23 minidspshd go-librespot[4116]: go-librespot daemon starting... Jun 21 14:22:23 minidspshd go-librespot[4116]: time="2025-06-21T14:22:23-06:00" level=info msg="running go-librespot 0.2.0" Jun 21 14:22:23 minidspshd go-librespot[4116]: time="2025-06-21T14:22:23-06:00" level=debug msg="app state loaded" Jun 21 14:22:23 minidspshd go-librespot[4116]: time="2025-06-21T14:22:23-06:00" level=debug msg="stored credentials not found" Jun 21 14:22:23 minidspshd go-librespot[4116]: time="2025-06-21T14:22:23-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 21 14:22:23 minidspshd go-librespot[4116]: time="2025-06-21T14:22:23-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 21 14:22:23 minidspshd go-librespot[4116]: time="2025-06-21T14:22:23-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 21 14:22:23 minidspshd go-librespot[4116]: time="2025-06-21T14:22:23-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 21 14:22:23 minidspshd go-librespot[4116]: time="2025-06-21T14:22:23-06:00" level=info msg="zeroconf server listening on port 38647" Jun 21 14:22:24 minidspshd go-librespot[4116]: time="2025-06-21T14:22:24-06:00" level=debug msg="obtained new client token: AAA0QBeR8L9ynb+9JXBqR5Jxc5EecIWtp557mRnHJFMHEQ3W4i+4z390GMkiDbkPwhGhlU8/0rz9QSZB9uV+MVvVi9QBGewt7wpvyLmITvqxceXBT+6G0NjBEW3icJJhqzDHnDj3JdvgzDdM1DuYLG5nTlnhVxX3SwEw5x0fQ5AtyacycjVIZwCMdwK+BFN+t6j7uK1IijVWJBlssCZDmlMrwAXvAgv2KrNx9D1/CiYtWkoFplmm" Jun 21 14:22:24 minidspshd go-librespot[4116]: time="2025-06-21T14:22:24-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jun 21 14:22:24 minidspshd go-librespot[4116]: time="2025-06-21T14:22:24-06:00" level=debug msg="completed keyexchange" Jun 21 14:22:24 minidspshd go-librespot[4116]: time="2025-06-21T14:22:24-06:00" level=debug msg="completed challenge" Jun 21 14:22:24 minidspshd go-librespot[4116]: time="2025-06-21T14:22:24-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 21 14:22:24 minidspshd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 21 14:22:24 minidspshd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 21 14:22:26 minidspshd volumio[688]: info: Initializing connection to go-librespot Websocket Jun 21 14:22:26 minidspshd volumio[688]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:22:27 minidspshd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 21 14:22:27 minidspshd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 236. Jun 21 14:22:27 minidspshd systemd[1]: Stopped go-librespot Daemon. Jun 21 14:22:27 minidspshd systemd[1]: Started go-librespot Daemon. Jun 21 14:22:27 minidspshd go-librespot[4124]: go-librespot daemon starting... Jun 21 14:22:27 minidspshd go-librespot[4124]: time="2025-06-21T14:22:27-06:00" level=info msg="running go-librespot 0.2.0" Jun 21 14:22:27 minidspshd go-librespot[4124]: time="2025-06-21T14:22:27-06:00" level=debug msg="app state loaded" Jun 21 14:22:27 minidspshd go-librespot[4124]: time="2025-06-21T14:22:27-06:00" level=debug msg="stored credentials not found" Jun 21 14:22:27 minidspshd go-librespot[4124]: time="2025-06-21T14:22:27-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 21 14:22:27 minidspshd sudo[4132]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 21 14:22:27 minidspshd sudo[4132]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 21 14:22:27 minidspshd sudo[4132]: pam_unix(sudo:session): session closed for user root Jun 21 14:22:27 minidspshd sudo[4135]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 21 14:22:27 minidspshd sudo[4135]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 21 14:22:27 minidspshd sudo[4135]: pam_unix(sudo:session): session closed for user root Jun 21 14:22:27 minidspshd volumio[688]: verbose: New Socket.io Connection to 192.168.0.222 from 192.168.0.213 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/137.0.0.0 Safari/537.36 Total Clients: 7 Jun 21 14:22:28 minidspshd sudo[4142]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 21 14:22:28 minidspshd sudo[4142]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 21 14:22:28 minidspshd go-librespot[4124]: time="2025-06-21T14:22:28-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 21 14:22:28 minidspshd go-librespot[4124]: time="2025-06-21T14:22:28-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 21 14:22:28 minidspshd go-librespot[4124]: time="2025-06-21T14:22:28-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 21 14:22:28 minidspshd sudo[4142]: pam_unix(sudo:session): session closed for user root Jun 21 14:22:28 minidspshd go-librespot[4124]: time="2025-06-21T14:22:28-06:00" level=info msg="zeroconf server listening on port 45789" Jun 21 14:22:28 minidspshd sudo[4145]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 21 14:22:28 minidspshd sudo[4145]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 21 14:22:28 minidspshd sudo[4145]: pam_unix(sudo:session): session closed for user root Jun 21 14:22:28 minidspshd volumio[688]: verbose: New Socket.io Connection to 192.168.0.222 from 192.168.0.213 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/137.0.0.0 Safari/537.36 Total Clients: 8 Jun 21 14:22:28 minidspshd volumio[688]: info: CoreCommandRouter::volumioGetState Jun 21 14:22:28 minidspshd volumio[688]: info: CorePlayQueue::getTrack 0 Jun 21 14:22:28 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jun 21 14:22:28 minidspshd volumio[688]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Jun 21 14:22:28 minidspshd volumio[688]: info: CoreCommandRouter::volumioGetVisibleSources Jun 21 14:22:28 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 21 14:22:28 minidspshd volumio[688]: info: Listing playlists Jun 21 14:22:28 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jun 21 14:22:28 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jun 21 14:22:28 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jun 21 14:22:28 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 21 14:22:28 minidspshd go-librespot[4124]: time="2025-06-21T14:22:28-06:00" level=debug msg="obtained new client token: AADsRcgD3AsDHSFFchEZFDFHBsNjnBc+aNTTEkb3sRZ26x8jWFkvFKUGRbM+CXlp2tDUYsuuolv06adotxJ+nSkGd3mgjG+x+9QXIzfej44xwNbRAns6fVPTQTofF+/LRBqk1h1e0C6VgMbGCkviHO2n0lRSV8q0rZG3o9O34PpyIQu0TThPNZtRCUdROGnTOe33Vbxq7BCWOqn56TT+hZczsj3LsuzMi34UQyIp7NT4wC1vuw4vW2M=" Jun 21 14:22:28 minidspshd go-librespot[4124]: time="2025-06-21T14:22:28-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jun 21 14:22:28 minidspshd go-librespot[4124]: time="2025-06-21T14:22:28-06:00" level=debug msg="completed keyexchange" Jun 21 14:22:28 minidspshd go-librespot[4124]: time="2025-06-21T14:22:28-06:00" level=debug msg="completed challenge" Jun 21 14:22:28 minidspshd go-librespot[4124]: time="2025-06-21T14:22:28-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 21 14:22:28 minidspshd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 21 14:22:28 minidspshd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 21 14:22:29 minidspshd volumio[688]: info: Initializing connection to go-librespot Websocket Jun 21 14:22:29 minidspshd volumio[688]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:22:30 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 21 14:22:30 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 21 14:22:31 minidspshd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 21 14:22:31 minidspshd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 237. Jun 21 14:22:31 minidspshd systemd[1]: Stopped go-librespot Daemon. Jun 21 14:22:31 minidspshd systemd[1]: Started go-librespot Daemon. Jun 21 14:22:31 minidspshd go-librespot[4149]: go-librespot daemon starting... Jun 21 14:22:31 minidspshd go-librespot[4149]: time="2025-06-21T14:22:31-06:00" level=info msg="running go-librespot 0.2.0" Jun 21 14:22:31 minidspshd go-librespot[4149]: time="2025-06-21T14:22:31-06:00" level=debug msg="app state loaded" Jun 21 14:22:31 minidspshd go-librespot[4149]: time="2025-06-21T14:22:31-06:00" level=debug msg="stored credentials not found" Jun 21 14:22:31 minidspshd go-librespot[4149]: time="2025-06-21T14:22:31-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 21 14:22:32 minidspshd volumio[688]: info: Initializing connection to go-librespot Websocket Jun 21 14:22:32 minidspshd go-librespot[4149]: time="2025-06-21T14:22:32-06:00" level=debug msg="new websocket client" Jun 21 14:22:32 minidspshd volumio[688]: info: Connection to go-librespot Websocket established Jun 21 14:22:32 minidspshd go-librespot[4149]: time="2025-06-21T14:22:32-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 21 14:22:32 minidspshd go-librespot[4149]: time="2025-06-21T14:22:32-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 21 14:22:32 minidspshd go-librespot[4149]: time="2025-06-21T14:22:32-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 21 14:22:32 minidspshd go-librespot[4149]: time="2025-06-21T14:22:32-06:00" level=info msg="zeroconf server listening on port 46617" Jun 21 14:22:32 minidspshd go-librespot[4149]: time="2025-06-21T14:22:32-06:00" level=debug msg="obtained new client token: AADjwdPOeVnWXyElNLXW35kuIykQJiNS6LUs5DMvwMq2WPLa25Api37smAXC35it05z4eziy6jE/iU8iR4QSmYOpxsxYmFzcShWS6QxSGASxJg09w+B1oiB8KQ7HzpxktQ7hUMSwqcHgrcn9xGUHW5QtrPRhYrzupZOrji/t1f+sipQQXnS/9pu35Tl0vTYes3HKh/raYjF81hbhiFs8SYo8czuCZwn+KwifBBttHSor1ewt5pic50k=" Jun 21 14:22:32 minidspshd go-librespot[4149]: time="2025-06-21T14:22:32-06:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused" Jun 21 14:22:32 minidspshd go-librespot[4149]: time="2025-06-21T14:22:32-06:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:443, retrying with a different AP" error="dial tcp 104.154.127.247:443: connect: connection refused" Jun 21 14:22:32 minidspshd go-librespot[4149]: time="2025-06-21T14:22:32-06:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:80, retrying with a different AP" error="dial tcp 104.154.127.247:80: connect: connection refused" Jun 21 14:22:32 minidspshd go-librespot[4149]: time="2025-06-21T14:22:32-06:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jun 21 14:22:33 minidspshd go-librespot[4149]: time="2025-06-21T14:22:33-06:00" level=debug msg="completed keyexchange" Jun 21 14:22:33 minidspshd go-librespot[4149]: time="2025-06-21T14:22:33-06:00" level=debug msg="completed challenge" Jun 21 14:22:33 minidspshd go-librespot[4149]: time="2025-06-21T14:22:33-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 21 14:22:33 minidspshd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 21 14:22:33 minidspshd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 21 14:22:33 minidspshd volumio[688]: info: Connection to go-librespot Websocket closed Jun 21 14:22:35 minidspshd volumio[688]: info: Getting Spotify volume Jun 21 14:22:35 minidspshd volumio[688]: (node:688) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:22:35 minidspshd volumio[688]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Jun 21 14:22:35 minidspshd volumio[688]: (node:688) 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: 77) Jun 21 14:22:35 minidspshd volumio[688]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Jun 21 14:22:35 minidspshd volumio[688]: info: CoreCommandRouter::volumioGetState Jun 21 14:22:35 minidspshd volumio[688]: info: CorePlayQueue::getTrack 0 Jun 21 14:22:35 minidspshd volumio[688]: SPOTIFY: RECEIVED VOLUMIO VOLUME 77 Jun 21 14:22:36 minidspshd volumio[688]: info: CoreCommandRouter::volumioPlay Jun 21 14:22:36 minidspshd volumio[688]: info: CoreStateMachine::play index undefined Jun 21 14:22:36 minidspshd volumio[688]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 21 14:22:36 minidspshd volumio[688]: info: CorePlayQueue::getTrack 0 Jun 21 14:22:36 minidspshd volumio[688]: info: CoreStateMachine::startPlaybackTimer Jun 21 14:22:36 minidspshd volumio[688]: info: CorePlayQueue::getTrack 0 Jun 21 14:22:36 minidspshd volumio[688]: info: [1750537356068] ControllerSpotify::clearAddPlayTrack Jun 21 14:22:36 minidspshd volumio[688]: info: Sending Spotify command with payload to local API: /player/play Jun 21 14:22:36 minidspshd volumio[688]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:22:36 minidspshd volumio[688]: info: Initializing connection to go-librespot Websocket Jun 21 14:22:36 minidspshd volumio[688]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:22:36 minidspshd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 21 14:22:36 minidspshd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 238. Jun 21 14:22:36 minidspshd systemd[1]: Stopped go-librespot Daemon. Jun 21 14:22:36 minidspshd systemd[1]: Started go-librespot Daemon. Jun 21 14:22:36 minidspshd go-librespot[4158]: go-librespot daemon starting... Jun 21 14:22:36 minidspshd go-librespot[4158]: time="2025-06-21T14:22:36-06:00" level=info msg="running go-librespot 0.2.0" Jun 21 14:22:36 minidspshd go-librespot[4158]: time="2025-06-21T14:22:36-06:00" level=debug msg="app state loaded" Jun 21 14:22:36 minidspshd go-librespot[4158]: time="2025-06-21T14:22:36-06:00" level=debug msg="stored credentials not found" Jun 21 14:22:36 minidspshd go-librespot[4158]: time="2025-06-21T14:22:36-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 21 14:22:36 minidspshd go-librespot[4158]: time="2025-06-21T14:22:36-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jun 21 14:22:36 minidspshd go-librespot[4158]: time="2025-06-21T14:22:36-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jun 21 14:22:36 minidspshd go-librespot[4158]: time="2025-06-21T14:22:36-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jun 21 14:22:36 minidspshd go-librespot[4158]: time="2025-06-21T14:22:36-06:00" level=info msg="zeroconf server listening on port 44343" Jun 21 14:22:37 minidspshd go-librespot[4158]: time="2025-06-21T14:22:37-06:00" level=debug msg="obtained new client token: AAD41YJAQmuuaj/NRBS0/xhLFusaoang7868kBYWjXQFTVIBotGbB/4e0PPz+Y2h1WFO3X9gtNcCf3sS8xFGYE4v8Evoh0KGx4PHGd2YJaUKDYHjKOh/r9I37deNSJkjcd05eXAWbWOPXAlXGN6d9wssSr49KbKm/dS4epwuqaiu1krApAn6TblOdMT4mula7jV0cb1f7rc/pHt67xFoNUbHnwI6ofiM5t2ZBVKyoFijJ1ctnos7" Jun 21 14:22:37 minidspshd go-librespot[4158]: time="2025-06-21T14:22:37-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jun 21 14:22:37 minidspshd go-librespot[4158]: time="2025-06-21T14:22:37-06:00" level=debug msg="completed keyexchange" Jun 21 14:22:37 minidspshd go-librespot[4158]: time="2025-06-21T14:22:37-06:00" level=debug msg="completed challenge" Jun 21 14:22:37 minidspshd go-librespot[4158]: time="2025-06-21T14:22:37-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 21 14:22:37 minidspshd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 21 14:22:37 minidspshd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 21 14:22:39 minidspshd volumio[688]: info: Initializing connection to go-librespot Websocket Jun 21 14:22:39 minidspshd volumio[688]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:22:40 minidspshd volumio[688]: info: CoreCommandRouter::volumioPlay Jun 21 14:22:40 minidspshd volumio[688]: info: CoreStateMachine::play index undefined Jun 21 14:22:40 minidspshd volumio[688]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 21 14:22:40 minidspshd volumio[688]: info: CorePlayQueue::getTrack 0 Jun 21 14:22:40 minidspshd volumio[688]: info: CoreStateMachine::startPlaybackTimer Jun 21 14:22:40 minidspshd volumio[688]: info: CorePlayQueue::getTrack 0 Jun 21 14:22:40 minidspshd volumio[688]: info: [1750537360241] ControllerSpotify::clearAddPlayTrack Jun 21 14:22:40 minidspshd volumio[688]: info: Sending Spotify command with payload to local API: /player/play Jun 21 14:22:40 minidspshd volumio[688]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:22:40 minidspshd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 21 14:22:40 minidspshd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 239. Jun 21 14:22:40 minidspshd systemd[1]: Stopped go-librespot Daemon. Jun 21 14:22:40 minidspshd systemd[1]: Started go-librespot Daemon. Jun 21 14:22:40 minidspshd go-librespot[4166]: go-librespot daemon starting... Jun 21 14:22:40 minidspshd go-librespot[4166]: time="2025-06-21T14:22:40-06:00" level=info msg="running go-librespot 0.2.0" Jun 21 14:22:40 minidspshd go-librespot[4166]: time="2025-06-21T14:22:40-06:00" level=debug msg="app state loaded" Jun 21 14:22:40 minidspshd go-librespot[4166]: time="2025-06-21T14:22:40-06:00" level=debug msg="stored credentials not found" Jun 21 14:22:40 minidspshd go-librespot[4166]: time="2025-06-21T14:22:40-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 21 14:22:40 minidspshd go-librespot[4166]: time="2025-06-21T14:22:40-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 21 14:22:40 minidspshd go-librespot[4166]: time="2025-06-21T14:22:40-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 21 14:22:40 minidspshd go-librespot[4166]: time="2025-06-21T14:22:40-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 21 14:22:40 minidspshd go-librespot[4166]: time="2025-06-21T14:22:40-06:00" level=info msg="zeroconf server listening on port 38173" Jun 21 14:22:41 minidspshd go-librespot[4166]: time="2025-06-21T14:22:41-06:00" level=debug msg="obtained new client token: AABnnYQg82ktDsY+b+SllWMDJhnYRAXlf5oveslvXlTn6SbFgBH7ua5htoYyczTMLqmi2RXcZAHEHhEMDicLG/78kgHoD9TSpr/myYxypbI7RPpHGqIvqDz1A9/bgsWETYavXsMPIiT6p8u6KaVAKt2UvNGMfaXkwevPHRAwxNotv7MQSGjqK029tEuOWkyKjA5d/BvmMPTccEv0C+jFpRuQsr2i2QGtp2Glm2fAAERSMCj+PD7A" Jun 21 14:22:41 minidspshd go-librespot[4166]: time="2025-06-21T14:22:41-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jun 21 14:22:41 minidspshd go-librespot[4166]: time="2025-06-21T14:22:41-06:00" level=debug msg="completed keyexchange" Jun 21 14:22:41 minidspshd go-librespot[4166]: time="2025-06-21T14:22:41-06:00" level=debug msg="completed challenge" Jun 21 14:22:41 minidspshd go-librespot[4166]: time="2025-06-21T14:22:41-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 21 14:22:41 minidspshd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 21 14:22:41 minidspshd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 21 14:22:42 minidspshd volumio[688]: info: Initializing connection to go-librespot Websocket Jun 21 14:22:42 minidspshd volumio[688]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:22:44 minidspshd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 21 14:22:44 minidspshd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 240. Jun 21 14:22:44 minidspshd systemd[1]: Stopped go-librespot Daemon. Jun 21 14:22:44 minidspshd systemd[1]: Started go-librespot Daemon. Jun 21 14:22:44 minidspshd go-librespot[4175]: go-librespot daemon starting... Jun 21 14:22:44 minidspshd go-librespot[4175]: time="2025-06-21T14:22:44-06:00" level=info msg="running go-librespot 0.2.0" Jun 21 14:22:44 minidspshd go-librespot[4175]: time="2025-06-21T14:22:44-06:00" level=debug msg="app state loaded" Jun 21 14:22:44 minidspshd go-librespot[4175]: time="2025-06-21T14:22:44-06:00" level=debug msg="stored credentials not found" Jun 21 14:22:44 minidspshd go-librespot[4175]: time="2025-06-21T14:22:44-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 21 14:22:44 minidspshd go-librespot[4175]: time="2025-06-21T14:22:44-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 21 14:22:44 minidspshd go-librespot[4175]: time="2025-06-21T14:22:44-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 21 14:22:44 minidspshd go-librespot[4175]: time="2025-06-21T14:22:44-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 21 14:22:44 minidspshd go-librespot[4175]: time="2025-06-21T14:22:44-06:00" level=info msg="zeroconf server listening on port 42169" Jun 21 14:22:45 minidspshd go-librespot[4175]: time="2025-06-21T14:22:45-06:00" level=debug msg="obtained new client token: AABQ4VrjRHehPHM9sFMCWbUujgyiY2kNTQeF8eTZplj8qsVajo+f1WEL1atUvn0UcccWSrfzaNtab9+O7GD6G2BjMtK1DKtTY8gyMqPkFDph3ZN0oN1giLVT8q3FC48t9L4SmzMVGefGClZ4+cNtecth+inZ8vDEWNneQUAzJiHS4nHJ0f8dFbiQnbhE7ZDycrcB8VqVonTVfpjfv6LlpvSdghTcXKvaMPAaJECsa2OM/lBo/hpz" Jun 21 14:22:45 minidspshd volumio[688]: info: Initializing connection to go-librespot Websocket Jun 21 14:22:45 minidspshd go-librespot[4175]: time="2025-06-21T14:22:45-06:00" level=debug msg="new websocket client" Jun 21 14:22:45 minidspshd volumio[688]: info: Connection to go-librespot Websocket established Jun 21 14:22:45 minidspshd go-librespot[4175]: time="2025-06-21T14:22:45-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jun 21 14:22:45 minidspshd go-librespot[4175]: time="2025-06-21T14:22:45-06:00" level=debug msg="completed keyexchange" Jun 21 14:22:45 minidspshd go-librespot[4175]: time="2025-06-21T14:22:45-06:00" level=debug msg="completed challenge" Jun 21 14:22:45 minidspshd go-librespot[4175]: time="2025-06-21T14:22:45-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 21 14:22:45 minidspshd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 21 14:22:45 minidspshd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 21 14:22:45 minidspshd volumio[688]: info: Connection to go-librespot Websocket closed Jun 21 14:22:46 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 21 14:22:46 minidspshd volumio[688]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Jun 21 14:22:46 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Jun 21 14:22:46 minidspshd volumio[688]: info: Received Get System Version Jun 21 14:22:46 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 21 14:22:46 minidspshd volumio[688]: info: Received Get System Info Jun 21 14:22:46 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 21 14:22:46 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 21 14:22:46 minidspshd volumio[688]: info: Discovery: Getting this device information Jun 21 14:22:46 minidspshd volumio[688]: info: CoreCommandRouter::volumioGetState Jun 21 14:22:46 minidspshd volumio[688]: info: CorePlayQueue::getTrack 0 Jun 21 14:22:46 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 21 14:22:48 minidspshd volumio[688]: info: Getting Spotify volume Jun 21 14:22:48 minidspshd volumio[688]: (node:688) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:22:48 minidspshd volumio[688]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Jun 21 14:22:48 minidspshd volumio[688]: (node:688) 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: 78) Jun 21 14:22:48 minidspshd volumio[688]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Jun 21 14:22:48 minidspshd volumio[688]: info: CoreCommandRouter::volumioGetState Jun 21 14:22:48 minidspshd volumio[688]: info: CorePlayQueue::getTrack 0 Jun 21 14:22:48 minidspshd volumio[688]: SPOTIFY: RECEIVED VOLUMIO VOLUME 77 Jun 21 14:22:48 minidspshd volumio[688]: info: Initializing connection to go-librespot Websocket Jun 21 14:22:48 minidspshd volumio[688]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:22:48 minidspshd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 21 14:22:48 minidspshd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 241. Jun 21 14:22:48 minidspshd systemd[1]: Stopped go-librespot Daemon. Jun 21 14:22:48 minidspshd systemd[1]: Started go-librespot Daemon. Jun 21 14:22:48 minidspshd go-librespot[4183]: go-librespot daemon starting... Jun 21 14:22:48 minidspshd go-librespot[4183]: time="2025-06-21T14:22:48-06:00" level=info msg="running go-librespot 0.2.0" Jun 21 14:22:48 minidspshd go-librespot[4183]: time="2025-06-21T14:22:48-06:00" level=debug msg="app state loaded" Jun 21 14:22:48 minidspshd go-librespot[4183]: time="2025-06-21T14:22:48-06:00" level=debug msg="stored credentials not found" Jun 21 14:22:48 minidspshd go-librespot[4183]: time="2025-06-21T14:22:48-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 21 14:22:49 minidspshd go-librespot[4183]: time="2025-06-21T14:22:49-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 21 14:22:49 minidspshd go-librespot[4183]: time="2025-06-21T14:22:49-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 21 14:22:49 minidspshd go-librespot[4183]: time="2025-06-21T14:22:49-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 21 14:22:49 minidspshd go-librespot[4183]: time="2025-06-21T14:22:49-06:00" level=info msg="zeroconf server listening on port 34839" Jun 21 14:22:49 minidspshd go-librespot[4183]: time="2025-06-21T14:22:49-06:00" level=debug msg="obtained new client token: AACWQVEUhMDZQk38QOCI7TcoEP0F+5Ldqr3NwtG5bVlDZYrjcBzQHxzQ3nUnzlE42SiNH6R2oSa2MJi2S3wdUv9FbrpNz/nIhBHS/lPBIUthXtYA+cbEu3RqZ20LD328r1vMLaLaxcOXPEaX4CmvLz19DjwlXSefLIBtR8oXhLwEOO3uGbAamXJXv0E6pkD8ktfQ9tEiSfMxBipaVMCiCMvD/9j+P/1tAHFX3gwxruHwHMrjpz8PLQg=" Jun 21 14:22:49 minidspshd go-librespot[4183]: time="2025-06-21T14:22:49-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jun 21 14:22:49 minidspshd go-librespot[4183]: time="2025-06-21T14:22:49-06:00" level=debug msg="completed keyexchange" Jun 21 14:22:49 minidspshd go-librespot[4183]: time="2025-06-21T14:22:49-06:00" level=debug msg="completed challenge" Jun 21 14:22:49 minidspshd go-librespot[4183]: time="2025-06-21T14:22:49-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 21 14:22:49 minidspshd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 21 14:22:49 minidspshd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 21 14:22:51 minidspshd volumio[688]: info: Initializing connection to go-librespot Websocket Jun 21 14:22:51 minidspshd volumio[688]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:22:52 minidspshd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 21 14:22:52 minidspshd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 242. Jun 21 14:22:52 minidspshd systemd[1]: Stopped go-librespot Daemon. Jun 21 14:22:52 minidspshd systemd[1]: Started go-librespot Daemon. Jun 21 14:22:52 minidspshd go-librespot[4191]: go-librespot daemon starting... Jun 21 14:22:53 minidspshd go-librespot[4191]: time="2025-06-21T14:22:53-06:00" level=info msg="running go-librespot 0.2.0" Jun 21 14:22:53 minidspshd go-librespot[4191]: time="2025-06-21T14:22:53-06:00" level=debug msg="app state loaded" Jun 21 14:22:53 minidspshd go-librespot[4191]: time="2025-06-21T14:22:53-06:00" level=debug msg="stored credentials not found" Jun 21 14:22:53 minidspshd go-librespot[4191]: time="2025-06-21T14:22:53-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 21 14:22:53 minidspshd go-librespot[4191]: time="2025-06-21T14:22:53-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 21 14:22:53 minidspshd go-librespot[4191]: time="2025-06-21T14:22:53-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 21 14:22:53 minidspshd go-librespot[4191]: time="2025-06-21T14:22:53-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 21 14:22:53 minidspshd go-librespot[4191]: time="2025-06-21T14:22:53-06:00" level=info msg="zeroconf server listening on port 37597" Jun 21 14:22:53 minidspshd go-librespot[4191]: time="2025-06-21T14:22:53-06:00" level=debug msg="obtained new client token: AAB4yvYjWNa8j0rxwn9f6XiDpVPphlEMyxTxlIs2RK0mRpkRWlM0lw01VMMPewXYjXz+m2Ts3uLDjNuLmHn6vVaTagn5rHcnrAqEr2n09WdkYHgK+rS4AGecQ6urShMeVH02BFvikSfXnGuemQ01JQfYjgIKyS42K2qrQR4PAgV1U6ijdnnDU4VT6sqC+cBYm0a9qy8SSm6heN14MwEBj3fpf92B5iTHfU/G7lRgSuuAwIV55OXWEfw=" Jun 21 14:22:53 minidspshd go-librespot[4191]: time="2025-06-21T14:22:53-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jun 21 14:22:53 minidspshd go-librespot[4191]: time="2025-06-21T14:22:53-06:00" level=debug msg="completed keyexchange" Jun 21 14:22:53 minidspshd go-librespot[4191]: time="2025-06-21T14:22:53-06:00" level=debug msg="completed challenge" Jun 21 14:22:53 minidspshd go-librespot[4191]: time="2025-06-21T14:22:53-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 21 14:22:53 minidspshd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 21 14:22:53 minidspshd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 21 14:22:54 minidspshd volumio[688]: info: Initializing connection to go-librespot Websocket Jun 21 14:22:54 minidspshd volumio[688]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:22:56 minidspshd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 21 14:22:56 minidspshd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 243. Jun 21 14:22:56 minidspshd systemd[1]: Stopped go-librespot Daemon. Jun 21 14:22:56 minidspshd systemd[1]: Started go-librespot Daemon. Jun 21 14:22:56 minidspshd go-librespot[4199]: go-librespot daemon starting... Jun 21 14:22:57 minidspshd go-librespot[4199]: time="2025-06-21T14:22:57-06:00" level=info msg="running go-librespot 0.2.0" Jun 21 14:22:57 minidspshd go-librespot[4199]: time="2025-06-21T14:22:57-06:00" level=debug msg="app state loaded" Jun 21 14:22:57 minidspshd go-librespot[4199]: time="2025-06-21T14:22:57-06:00" level=debug msg="stored credentials not found" Jun 21 14:22:57 minidspshd go-librespot[4199]: time="2025-06-21T14:22:57-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 21 14:22:57 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Jun 21 14:22:57 minidspshd volumio[688]: info: In handleBrowseUri, curUri=spotify Jun 21 14:22:57 minidspshd volumio[688]: info: CoreCommandRouter::volumioGetQueue Jun 21 14:22:57 minidspshd volumio[688]: info: CoreStateMachine::getQueue Jun 21 14:22:57 minidspshd volumio[688]: info: CorePlayQueue::getQueue Jun 21 14:22:57 minidspshd volumio[688]: info: Preload queue cleared Jun 21 14:22:57 minidspshd volumio[688]: info: Preload queue cleared Jun 21 14:22:57 minidspshd volumio[688]: info: Preload queue cleared Jun 21 14:22:57 minidspshd volumio[688]: info: Preload queue cleared Jun 21 14:22:57 minidspshd go-librespot[4199]: time="2025-06-21T14:22:57-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 21 14:22:57 minidspshd go-librespot[4199]: time="2025-06-21T14:22:57-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 21 14:22:57 minidspshd go-librespot[4199]: time="2025-06-21T14:22:57-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 21 14:22:57 minidspshd go-librespot[4199]: time="2025-06-21T14:22:57-06:00" level=info msg="zeroconf server listening on port 39521" Jun 21 14:22:57 minidspshd volumio[688]: info: Initializing connection to go-librespot Websocket Jun 21 14:22:57 minidspshd go-librespot[4199]: time="2025-06-21T14:22:57-06:00" level=debug msg="new websocket client" Jun 21 14:22:57 minidspshd volumio[688]: info: Connection to go-librespot Websocket established Jun 21 14:22:57 minidspshd go-librespot[4199]: time="2025-06-21T14:22:57-06:00" level=debug msg="obtained new client token: AABleWWcfm+YpZWTlbNOU7Kr2zXGwibrWyB3VhAvbpPX1MUWbqVbVbRaC1szlHw16nsbhXDqgd05EWmd90howV57C1dfn2cSzge3jNXbYJqUyPBZqJ5NeW5xNMqIqm63AB9G+IoorU15ge+TvD00Pm4XWBBFZf3Y9xB8AydSN2/MhshbMvoDtHMuKUcTCwVIV33zps8mhFccBQh9f4TLdGj0V40e7CCF0H2/251GCySmuvQQSNl8DJM=" Jun 21 14:22:57 minidspshd go-librespot[4199]: time="2025-06-21T14:22:57-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jun 21 14:22:58 minidspshd go-librespot[4199]: time="2025-06-21T14:22:58-06:00" level=debug msg="completed keyexchange" Jun 21 14:22:58 minidspshd go-librespot[4199]: time="2025-06-21T14:22:58-06:00" level=debug msg="completed challenge" Jun 21 14:22:58 minidspshd go-librespot[4199]: time="2025-06-21T14:22:58-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 21 14:22:58 minidspshd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 21 14:22:58 minidspshd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 21 14:22:58 minidspshd volumio[688]: info: Connection to go-librespot Websocket closed Jun 21 14:23:00 minidspshd volumio[688]: info: Getting Spotify volume Jun 21 14:23:00 minidspshd volumio[688]: (node:688) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:23:00 minidspshd volumio[688]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Jun 21 14:23:00 minidspshd volumio[688]: (node:688) 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: 79) Jun 21 14:23:00 minidspshd volumio[688]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Jun 21 14:23:00 minidspshd volumio[688]: info: CoreCommandRouter::volumioGetState Jun 21 14:23:00 minidspshd volumio[688]: info: CorePlayQueue::getTrack 0 Jun 21 14:23:00 minidspshd volumio[688]: SPOTIFY: RECEIVED VOLUMIO VOLUME 77 Jun 21 14:23:01 minidspshd volumio[688]: info: Initializing connection to go-librespot Websocket Jun 21 14:23:01 minidspshd volumio[688]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:23:01 minidspshd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 21 14:23:01 minidspshd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 244. Jun 21 14:23:01 minidspshd systemd[1]: Stopped go-librespot Daemon. Jun 21 14:23:01 minidspshd systemd[1]: Started go-librespot Daemon. Jun 21 14:23:01 minidspshd go-librespot[4207]: go-librespot daemon starting... Jun 21 14:23:01 minidspshd go-librespot[4207]: time="2025-06-21T14:23:01-06:00" level=info msg="running go-librespot 0.2.0" Jun 21 14:23:01 minidspshd go-librespot[4207]: time="2025-06-21T14:23:01-06:00" level=debug msg="app state loaded" Jun 21 14:23:01 minidspshd go-librespot[4207]: time="2025-06-21T14:23:01-06:00" level=debug msg="stored credentials not found" Jun 21 14:23:01 minidspshd go-librespot[4207]: time="2025-06-21T14:23:01-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 21 14:23:01 minidspshd go-librespot[4207]: time="2025-06-21T14:23:01-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jun 21 14:23:01 minidspshd go-librespot[4207]: time="2025-06-21T14:23:01-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jun 21 14:23:01 minidspshd go-librespot[4207]: time="2025-06-21T14:23:01-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jun 21 14:23:01 minidspshd go-librespot[4207]: time="2025-06-21T14:23:01-06:00" level=info msg="zeroconf server listening on port 33923" Jun 21 14:23:01 minidspshd go-librespot[4207]: time="2025-06-21T14:23:01-06:00" level=debug msg="obtained new client token: AADl6XUsjl1+RwdRUE/Yg6DvSivXT7MmdMHtlHxQHMOXuabezAYBirj0ZKinWBlwBuOduHYe2uimGetabGxQ4U+T3xjIJGu3cEz+Bii7Qovm3LVhggAw3x2/Kl+Tm4+cAWP/72Xy4gqqHNIA36utH3pinGw3x6KqS7FiHawEUpkx2NjMoC8NR2pWKlrjNxNHCINFW4prWTo7XQTkMRVk3HyNQCfY5yF/uCX/gFM+ICPtQPp1Ee3jdy4=" Jun 21 14:23:02 minidspshd go-librespot[4207]: time="2025-06-21T14:23:02-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jun 21 14:23:02 minidspshd go-librespot[4207]: time="2025-06-21T14:23:02-06:00" level=debug msg="completed keyexchange" Jun 21 14:23:02 minidspshd go-librespot[4207]: time="2025-06-21T14:23:02-06:00" level=debug msg="completed challenge" Jun 21 14:23:02 minidspshd go-librespot[4207]: time="2025-06-21T14:23:02-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 21 14:23:02 minidspshd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 21 14:23:02 minidspshd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 21 14:23:04 minidspshd volumio[688]: info: Initializing connection to go-librespot Websocket Jun 21 14:23:04 minidspshd volumio[688]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:23:05 minidspshd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 21 14:23:05 minidspshd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 245. Jun 21 14:23:05 minidspshd systemd[1]: Stopped go-librespot Daemon. Jun 21 14:23:05 minidspshd systemd[1]: Started go-librespot Daemon. Jun 21 14:23:05 minidspshd go-librespot[4215]: go-librespot daemon starting... Jun 21 14:23:05 minidspshd go-librespot[4215]: time="2025-06-21T14:23:05-06:00" level=info msg="running go-librespot 0.2.0" Jun 21 14:23:05 minidspshd go-librespot[4215]: time="2025-06-21T14:23:05-06:00" level=debug msg="app state loaded" Jun 21 14:23:05 minidspshd go-librespot[4215]: time="2025-06-21T14:23:05-06:00" level=debug msg="stored credentials not found" Jun 21 14:23:05 minidspshd go-librespot[4215]: time="2025-06-21T14:23:05-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 21 14:23:05 minidspshd go-librespot[4215]: time="2025-06-21T14:23:05-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jun 21 14:23:05 minidspshd go-librespot[4215]: time="2025-06-21T14:23:05-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jun 21 14:23:05 minidspshd go-librespot[4215]: time="2025-06-21T14:23:05-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jun 21 14:23:05 minidspshd go-librespot[4215]: time="2025-06-21T14:23:05-06:00" level=info msg="zeroconf server listening on port 41581" Jun 21 14:23:06 minidspshd go-librespot[4215]: time="2025-06-21T14:23:06-06:00" level=debug msg="obtained new client token: AACDuxpupmT79XU7dhtmJ+4EeIHjMhsVHpLVC7DTde7l8tIkmLc7IplwCZA5ZxcFbn2vmkpHXLUfMQiFYYSy8e4ig7W2U9WCC0jctLMG0lpDYhVE1aaWgUmHzLv8zC0DsCvhKkrjnEUNmj2t8NgxLwHdS4m7tLTtPxxedJV1zT5vDWDN6YpPhKRItSROFaDQQifyseS4krcTuQxIIsnCcj6nM/zrAz14Ffp16DLrOwNq++O8pBNF" Jun 21 14:23:06 minidspshd go-librespot[4215]: time="2025-06-21T14:23:06-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jun 21 14:23:06 minidspshd go-librespot[4215]: time="2025-06-21T14:23:06-06:00" level=debug msg="completed keyexchange" Jun 21 14:23:06 minidspshd go-librespot[4215]: time="2025-06-21T14:23:06-06:00" level=debug msg="completed challenge" Jun 21 14:23:06 minidspshd go-librespot[4215]: time="2025-06-21T14:23:06-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 21 14:23:06 minidspshd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 21 14:23:06 minidspshd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 21 14:23:07 minidspshd volumio[688]: info: Initializing connection to go-librespot Websocket Jun 21 14:23:07 minidspshd volumio[688]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:23:08 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Jun 21 14:23:08 minidspshd volumio[688]: info: In handleBrowseUri, curUri=spotify:playlist:37i9dQZF1DX4JAvHpjipBk Jun 21 14:23:09 minidspshd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 21 14:23:09 minidspshd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 246. Jun 21 14:23:09 minidspshd systemd[1]: Stopped go-librespot Daemon. Jun 21 14:23:09 minidspshd systemd[1]: Started go-librespot Daemon. Jun 21 14:23:09 minidspshd go-librespot[4225]: go-librespot daemon starting... Jun 21 14:23:09 minidspshd go-librespot[4225]: time="2025-06-21T14:23:09-06:00" level=info msg="running go-librespot 0.2.0" Jun 21 14:23:09 minidspshd go-librespot[4225]: time="2025-06-21T14:23:09-06:00" level=debug msg="app state loaded" Jun 21 14:23:09 minidspshd go-librespot[4225]: time="2025-06-21T14:23:09-06:00" level=debug msg="stored credentials not found" Jun 21 14:23:09 minidspshd go-librespot[4225]: time="2025-06-21T14:23:09-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 21 14:23:09 minidspshd go-librespot[4225]: time="2025-06-21T14:23:09-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jun 21 14:23:09 minidspshd go-librespot[4225]: time="2025-06-21T14:23:09-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jun 21 14:23:09 minidspshd go-librespot[4225]: time="2025-06-21T14:23:09-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jun 21 14:23:09 minidspshd go-librespot[4225]: time="2025-06-21T14:23:09-06:00" level=info msg="zeroconf server listening on port 35385" Jun 21 14:23:10 minidspshd volumio[688]: info: Initializing connection to go-librespot Websocket Jun 21 14:23:10 minidspshd go-librespot[4225]: time="2025-06-21T14:23:10-06:00" level=debug msg="new websocket client" Jun 21 14:23:10 minidspshd volumio[688]: info: Connection to go-librespot Websocket established Jun 21 14:23:10 minidspshd go-librespot[4225]: time="2025-06-21T14:23:10-06:00" level=debug msg="obtained new client token: AABX893Lh+PY4FFsAvgMZuT4nLDE6Jsv6kBMwBfhOqYK6ZOIhCyRLbbojiMiq6bUlEYLZARvQxkYeQQZcPvvNX3xIqT+BE5ZGUugiIxRGtcaT3idR7M0VL+2snAW1DilESJeF1/McVkcL+M0qa5Fs80UYbumUWRwstHCqiuyimgwE8v/uWGaaIYxn64r4Vx8wxtOIyWv6OTfgRiE2EV0JawtJ2HDka96VtBZnChPnyMj7Gq574IY" Jun 21 14:23:10 minidspshd go-librespot[4225]: time="2025-06-21T14:23:10-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jun 21 14:23:10 minidspshd go-librespot[4225]: time="2025-06-21T14:23:10-06:00" level=debug msg="completed keyexchange" Jun 21 14:23:10 minidspshd go-librespot[4225]: time="2025-06-21T14:23:10-06:00" level=debug msg="completed challenge" Jun 21 14:23:10 minidspshd go-librespot[4225]: time="2025-06-21T14:23:10-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 21 14:23:10 minidspshd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 21 14:23:10 minidspshd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 21 14:23:10 minidspshd volumio[688]: info: Connection to go-librespot Websocket closed Jun 21 14:23:10 minidspshd volumio[688]: info: Preload queue cleared Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:6V7bxWg4mmuU4ILbYPQJvd Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:7o3xJRQhpHRZ6IbyQX2xrp Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:64zQbQTwu4ppBEfWyhst9t Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:0iIcuwia47B5bzjVpyUwyI Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:139nLHDFZNr3anx8CpUy7u Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:5XpZFOSIvQlHLZV39uHNkW Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:08lwoqbPtnLRzBZW92dm0l Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:5OdPAqU4a0EZq8LOJgO5og Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:1lbNgoJ5iMrMluCyhI4OQP Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:6ugu9WpCEHXmns0PiqYTU1 Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:4Km9FSF9iaQiTLnFPdbPom Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:3yKgOMlm0LFpm9T2AhGWJJ Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:2PcZiMr9bRNtRikrN7s6bL Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:6svat6LhQXRAnALB7CkUg5 Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:6B9j1SQnmtHa0i5FiifFRi Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:6CBurTHmYJhIcDD72Qgjnm Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:4SNPg0KDZ859vauVTaNg7i Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:1UlkpIKiVchDMB03AN6LmT Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:3K5bLOU8pMGrDsPCfdL25g Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:3zgZgaTkhrEhP8isvTw4Fr Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:7v5VghHzM0iIoSQXGuZNzb Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:0TeyADr2CzTOdwfsZCKn3c Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:260EW8FU6e45oZ6sylXrfS Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:47w21Lurejb4n3r09H19Fz Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:2XbsqBrOdYjm0OLBEepID7 Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:4R7VfFjWXa62I3nDmiwAso Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:12wvLk3fOmOonVmH0TtQ8L Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:4kd3HIkMbwO4sVgkYkrBGo Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:1xOqGUkyxGQRdCvGpvWKmL Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:1qHDg5ObxDpRZjoqPQGIyK Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:6Df0RNShcnfIJmrRoJ6Gc9 Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:13tMf761hDpFCGUiSZcNhk Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:22CKFavEurPuJJsOFaobac Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:3f2MxvJB9kQYSJFADpwE0A Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:5g3PPNIHL5yMci2pio9ZoI Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:4EneW3YDPf0nWxcdIup9mW Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:00uXDC6A3RK2HJlTK6h0Ak Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:4mOWnjz30frv1pKMM6DNfv Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:5VdQP3CLYQrTOb9YZipDqC Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:2rsTdV5sQmTTfX4SDsgT3o Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:6FVK5UcCwZ3k34vT2wenhd Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:4zz49nB3rFzVPrEQmwuSrU Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:1CDo1ZxKO7LxGIZNYZ4nFL Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:1TsDNh8OuRcGfNX4Dz8oVl Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:6A1aAR1Yr4xYRcJ2VIdoE4 Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:40WLAegRTL6PuZexdJiCYI Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:4vChLQrMY67IWFxYCcQUVQ Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:3roiUw3YFNlKE3u8qMmVmw Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:4p0uVFAXKUISu8yp9gNtWE Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:0Pr6mooJDSPrUJDwP8ZXUW Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:2qGj53vRPm0NEKGk6ymawI Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:7BVzUgIqxwiwPbMz35z3ZE Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:30ENhWMCzVNC0aaVW7gaHu Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:7xkyqFdogcqpGKkn3baJ6d Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:29CvrDmscTVF9tD5Pyd8hQ Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:47I8eRmRwU4EUX3HUqhFfp Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:01WDhc8gxD59xkrUDqCe5t Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:2nmChkMss0FEoKEWfCLGRp Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:5Bx56ljKGDDZ4CpjBO0CLJ Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:7mKuFtTJtE1pl3MhKv2GU1 Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:1cMU20gleQO9xYjCeni3DJ Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:6vS3l6JjTOp8LOZfDcKWDX Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:0jr7FK6kP2W9JFGsG4bYF4 Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:3Z23sDc2J9ZkmFiMStRoIp Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:4yiQrkO2yqBhjJbBkxexpu Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:5R0uszDwzrAEtxMgTwoIbt Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:0h4aBq7QsZiNwwsxQlwQoP Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:6fjJaCurUYhcMp9ZZ94u04 Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:5vRvTccr05SrSnqVvNAmVX Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:3JGjIeUQlPemqBqBZ1e59r Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:3aWWdmdsBva7kiOnacL4tf Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:2ypJczNpROoMFYTN5vcv9g Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:7wgOJAyT89i2WOcT4a7Z67 Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:19E4xm8OhtXeQ93ccRCeJJ Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:4POSbPMxN0VrfighTfRtuc Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:2aOKR3QxNyOagxfB7V8ZVa Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:66rNsPhOHgw2UWTWRf5S9I Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:3zTqj90l1JdCzBBhxk5Z7U Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:7zPfFxH8WxUUffU8rqB4kU Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:5sW5xwuhgkvFA6CgY4key2 Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:0NBAZGnkzLPbr7mxMlbx5H Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:7t9PnUaT9vgSqP18amgVY8 Jun 21 14:23:10 minidspshd volumio[688]: info: Preloading song: spotify:track:7AVZ2T5nku3TKyZlPPXLEd Jun 21 14:23:11 minidspshd volumio[688]: info: Preloading song: spotify:track:2cymECfb8aQNVEb2u7QSon Jun 21 14:23:11 minidspshd volumio[688]: info: Preloading song: spotify:track:413Pc87SwoEUIui4hFyGOU Jun 21 14:23:11 minidspshd volumio[688]: info: Preloading song: spotify:track:4yTInPCpzqBNeHmcWCvjiz Jun 21 14:23:11 minidspshd volumio[688]: info: Preloading song: spotify:track:7C9znPRuIPDj20Tzqvm7kf Jun 21 14:23:11 minidspshd volumio[688]: info: Preloading song: spotify:track:0MfseoOUoi3cOT878tC9zv Jun 21 14:23:11 minidspshd volumio[688]: info: Preloading song: spotify:track:1rKQjUhF9zFJmuUotr3VkV Jun 21 14:23:11 minidspshd volumio[688]: info: Preloading song: spotify:track:7Hcnebss2poEHrJJUiS0QN Jun 21 14:23:11 minidspshd volumio[688]: info: Preloading song: spotify:track:34OWdGICYrtFXRcOlZKSyb Jun 21 14:23:11 minidspshd volumio[688]: info: Preloading song: spotify:track:2Ri6KgtAyWJwJNc8ooQcGs Jun 21 14:23:11 minidspshd volumio[688]: info: Preloading song: spotify:track:6LDB1KY7hbf9r7iiroZzPC Jun 21 14:23:11 minidspshd volumio[688]: info: Preloading song: spotify:track:0Mq7egfvtSRmwVjkGkmPfI Jun 21 14:23:11 minidspshd volumio[688]: info: Preloading song: spotify:track:3IDyBwF4zAd7sLNOUEAIU2 Jun 21 14:23:11 minidspshd volumio[688]: info: Preloading song: spotify:track:5hBTLtFdMIEcv0MB5fOPPY Jun 21 14:23:11 minidspshd volumio[688]: info: Preloading song: spotify:track:1c1cc2RY1oCNf0hr3jCy3x Jun 21 14:23:11 minidspshd volumio[688]: info: Preloading song: spotify:track:6kESVt7m9Wn2WcS1OGOOmC Jun 21 14:23:11 minidspshd volumio[688]: info: Preloading song: spotify:track:4cWPQXwN7p0RKihlUlcOUf Jun 21 14:23:11 minidspshd volumio[688]: info: Preloading song: spotify:track:1aumaeh5sU4VbH1ESkWaPO Jun 21 14:23:11 minidspshd volumio[688]: info: Exploding uri spotify:track:6V7bxWg4mmuU4ILbYPQJvd in service spop Jun 21 14:23:11 minidspshd volumio[688]: SPOTIFY: EXPLODING URI:spotify:track:6V7bxWg4mmuU4ILbYPQJvd Jun 21 14:23:11 minidspshd volumio[688]: info: Exploding uri spotify:track:7o3xJRQhpHRZ6IbyQX2xrp in service spop Jun 21 14:23:11 minidspshd volumio[688]: SPOTIFY: EXPLODING URI:spotify:track:7o3xJRQhpHRZ6IbyQX2xrp Jun 21 14:23:11 minidspshd volumio[688]: info: Exploding uri spotify:track:64zQbQTwu4ppBEfWyhst9t in service spop Jun 21 14:23:11 minidspshd volumio[688]: SPOTIFY: EXPLODING URI:spotify:track:64zQbQTwu4ppBEfWyhst9t Jun 21 14:23:11 minidspshd volumio[688]: info: Exploding uri spotify:track:0iIcuwia47B5bzjVpyUwyI in service spop Jun 21 14:23:11 minidspshd volumio[688]: SPOTIFY: EXPLODING URI:spotify:track:0iIcuwia47B5bzjVpyUwyI Jun 21 14:23:11 minidspshd volumio[688]: info: Exploding uri spotify:track:139nLHDFZNr3anx8CpUy7u in service spop Jun 21 14:23:11 minidspshd volumio[688]: SPOTIFY: EXPLODING URI:spotify:track:139nLHDFZNr3anx8CpUy7u Jun 21 14:23:11 minidspshd volumio[688]: info: Exploding uri spotify:track:5XpZFOSIvQlHLZV39uHNkW in service spop Jun 21 14:23:11 minidspshd volumio[688]: SPOTIFY: EXPLODING URI:spotify:track:5XpZFOSIvQlHLZV39uHNkW Jun 21 14:23:11 minidspshd volumio[688]: info: Exploding uri spotify:track:08lwoqbPtnLRzBZW92dm0l in service spop Jun 21 14:23:11 minidspshd volumio[688]: SPOTIFY: EXPLODING URI:spotify:track:08lwoqbPtnLRzBZW92dm0l Jun 21 14:23:11 minidspshd volumio[688]: info: Exploding uri spotify:track:5OdPAqU4a0EZq8LOJgO5og in service spop Jun 21 14:23:11 minidspshd volumio[688]: SPOTIFY: EXPLODING URI:spotify:track:5OdPAqU4a0EZq8LOJgO5og Jun 21 14:23:11 minidspshd volumio[688]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6V7bxWg4mmuU4ILbYPQJvd","service":"spop","name":"Mr Electric Blue","artist":"Benson Boone","album":"American Heart","type":"song","duration":190,"albumart":"https://i.scdn.co/image/ab67616d0000b27311b6c087ac030b4e396e32c0","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 21 14:23:11 minidspshd volumio[688]: info: Exploding uri spotify:track:1lbNgoJ5iMrMluCyhI4OQP in service spop Jun 21 14:23:11 minidspshd volumio[688]: SPOTIFY: EXPLODING URI:spotify:track:1lbNgoJ5iMrMluCyhI4OQP Jun 21 14:23:11 minidspshd volumio[688]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:64zQbQTwu4ppBEfWyhst9t","service":"spop","name":"Papasito","artist":"KAROL G","album":"Tropicoqueta","type":"song","duration":167,"albumart":"https://i.scdn.co/image/ab67616d0000b2734018a6ba07312ec74af169e6","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 21 14:23:11 minidspshd volumio[688]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0iIcuwia47B5bzjVpyUwyI","service":"spop","name":"Drive (From F1® The Movie)","artist":"Ed Sheeran","album":"Drive (From F1® The Movie)","type":"song","duration":187,"albumart":"https://i.scdn.co/image/ab67616d0000b273a54b771b4e4bd658d3b3de11","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 21 14:23:11 minidspshd volumio[688]: info: Exploding uri spotify:track:6ugu9WpCEHXmns0PiqYTU1 in service spop Jun 21 14:23:11 minidspshd volumio[688]: SPOTIFY: EXPLODING URI:spotify:track:6ugu9WpCEHXmns0PiqYTU1 Jun 21 14:23:11 minidspshd volumio[688]: info: Exploding uri spotify:track:4Km9FSF9iaQiTLnFPdbPom in service spop Jun 21 14:23:11 minidspshd volumio[688]: SPOTIFY: EXPLODING URI:spotify:track:4Km9FSF9iaQiTLnFPdbPom Jun 21 14:23:11 minidspshd volumio[688]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5XpZFOSIvQlHLZV39uHNkW","service":"spop","name":"Hammer","artist":"Lorde","album":"Hammer","type":"song","duration":193,"albumart":"https://i.scdn.co/image/ab67616d0000b2736c6519d78212014126753fa0","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 21 14:23:11 minidspshd volumio[688]: info: Exploding uri spotify:track:3yKgOMlm0LFpm9T2AhGWJJ in service spop Jun 21 14:23:11 minidspshd volumio[688]: SPOTIFY: EXPLODING URI:spotify:track:3yKgOMlm0LFpm9T2AhGWJJ Jun 21 14:23:11 minidspshd volumio[688]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:139nLHDFZNr3anx8CpUy7u","service":"spop","name":"Outside","artist":"Cardi B","album":"Outside","type":"song","duration":206,"albumart":"https://i.scdn.co/image/ab67616d0000b2732dd15638161a3bf8f7053f11","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 21 14:23:11 minidspshd volumio[688]: info: Exploding uri spotify:track:2PcZiMr9bRNtRikrN7s6bL in service spop Jun 21 14:23:11 minidspshd volumio[688]: SPOTIFY: EXPLODING URI:spotify:track:2PcZiMr9bRNtRikrN7s6bL Jun 21 14:23:11 minidspshd volumio[688]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:08lwoqbPtnLRzBZW92dm0l","service":"spop","name":"All over me","artist":"HAIM","album":"I quit","type":"song","duration":202,"albumart":"https://i.scdn.co/image/ab67616d0000b273eecadfdf560be4a6b32273a5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 21 14:23:11 minidspshd volumio[688]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5OdPAqU4a0EZq8LOJgO5og","service":"spop","name":"All Gas No Brakes (feat. BigXthaPlug)","artist":"Teddy Swims","album":"All Gas No Brakes (feat. BigXthaPlug)","type":"song","duration":163,"albumart":"https://i.scdn.co/image/ab67616d0000b273066745c7a81c4df691113397","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 21 14:23:11 minidspshd volumio[688]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7o3xJRQhpHRZ6IbyQX2xrp","service":"spop","name":"we never dated","artist":"sombr","album":"we never dated","type":"song","duration":196,"albumart":"https://i.scdn.co/image/ab67616d0000b273ebcf5477fe13ea664d6cef84","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 21 14:23:11 minidspshd volumio[688]: info: Exploding uri spotify:track:6svat6LhQXRAnALB7CkUg5 in service spop Jun 21 14:23:11 minidspshd volumio[688]: SPOTIFY: EXPLODING URI:spotify:track:6svat6LhQXRAnALB7CkUg5 Jun 21 14:23:11 minidspshd volumio[688]: info: Exploding uri spotify:track:6B9j1SQnmtHa0i5FiifFRi in service spop Jun 21 14:23:11 minidspshd volumio[688]: SPOTIFY: EXPLODING URI:spotify:track:6B9j1SQnmtHa0i5FiifFRi Jun 21 14:23:11 minidspshd volumio[688]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1lbNgoJ5iMrMluCyhI4OQP","service":"spop","name":"Victory Lap","artist":"Fred again..","album":"Victory Lap","type":"song","duration":165,"albumart":"https://i.scdn.co/image/ab67616d0000b273ed96e511d87235ac3e767382","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 21 14:23:11 minidspshd volumio[688]: info: Exploding uri spotify:track:6CBurTHmYJhIcDD72Qgjnm in service spop Jun 21 14:23:11 minidspshd volumio[688]: SPOTIFY: EXPLODING URI:spotify:track:6CBurTHmYJhIcDD72Qgjnm Jun 21 14:23:11 minidspshd volumio[688]: info: Exploding uri spotify:track:4SNPg0KDZ859vauVTaNg7i in service spop Jun 21 14:23:11 minidspshd volumio[688]: SPOTIFY: EXPLODING URI:spotify:track:4SNPg0KDZ859vauVTaNg7i Jun 21 14:23:11 minidspshd volumio[688]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3yKgOMlm0LFpm9T2AhGWJJ","service":"spop","name":"GUILT TRIPPIN (feat. Sexyy Red)","artist":"Central Cee","album":"GUILT TRIPPIN (feat. Sexyy Red)","type":"song","duration":153,"albumart":"https://i.scdn.co/image/ab67616d0000b27345d87e3f05f90ff6b5e106d3","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 21 14:23:11 minidspshd volumio[688]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6ugu9WpCEHXmns0PiqYTU1","service":"spop","name":"Not Like That Anymore","artist":"Lola Young","album":"Not Like That Anymore","type":"song","duration":202,"albumart":"https://i.scdn.co/image/ab67616d0000b2730508ba89402f61af6d4d6d19","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 21 14:23:11 minidspshd volumio[688]: info: Exploding uri spotify:track:1UlkpIKiVchDMB03AN6LmT in service spop Jun 21 14:23:11 minidspshd volumio[688]: SPOTIFY: EXPLODING URI:spotify:track:1UlkpIKiVchDMB03AN6LmT Jun 21 14:23:11 minidspshd volumio[688]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4Km9FSF9iaQiTLnFPdbPom","service":"spop","name":"6 Months Later","artist":"Megan Moroney","album":"6 Months Later","type":"song","duration":182,"albumart":"https://i.scdn.co/image/ab67616d0000b2734310d50745941c4c14a69314","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 21 14:23:11 minidspshd volumio[688]: info: Exploding uri spotify:track:3K5bLOU8pMGrDsPCfdL25g in service spop Jun 21 14:23:11 minidspshd volumio[688]: SPOTIFY: EXPLODING URI:spotify:track:3K5bLOU8pMGrDsPCfdL25g Jun 21 14:23:11 minidspshd volumio[688]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2PcZiMr9bRNtRikrN7s6bL","service":"spop","name":"Bodies (with JID)","artist":"Offset","album":"Bodies (with JID)","type":"song","duration":178,"albumart":"https://i.scdn.co/image/ab67616d0000b273572a0f748d0801d7bea5f245","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 21 14:23:11 minidspshd volumio[688]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6svat6LhQXRAnALB7CkUg5","service":"spop","name":"back of the club","artist":"kwn","album":"with all due respect","type":"song","duration":273,"albumart":"https://i.scdn.co/image/ab67616d0000b2732c3c238c0777860427ca66aa","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 21 14:23:11 minidspshd volumio[688]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6B9j1SQnmtHa0i5FiifFRi","service":"spop","name":"Qué Motor","artist":"Neton Vega","album":"Qué Motor","type":"song","duration":187,"albumart":"https://i.scdn.co/image/ab67616d0000b273f843f2188373694543b6bf26","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 21 14:23:11 minidspshd volumio[688]: info: Exploding uri spotify:track:3zgZgaTkhrEhP8isvTw4Fr in service spop Jun 21 14:23:11 minidspshd volumio[688]: SPOTIFY: EXPLODING URI:spotify:track:3zgZgaTkhrEhP8isvTw4Fr Jun 21 14:23:11 minidspshd volumio[688]: info: Exploding uri spotify:track:7v5VghHzM0iIoSQXGuZNzb in service spop Jun 21 14:23:11 minidspshd volumio[688]: SPOTIFY: EXPLODING URI:spotify:track:7v5VghHzM0iIoSQXGuZNzb Jun 21 14:23:12 minidspshd volumio[688]: info: Exploding uri spotify:track:0TeyADr2CzTOdwfsZCKn3c in service spop Jun 21 14:23:12 minidspshd volumio[688]: SPOTIFY: EXPLODING URI:spotify:track:0TeyADr2CzTOdwfsZCKn3c Jun 21 14:23:12 minidspshd volumio[688]: info: Exploding uri spotify:track:260EW8FU6e45oZ6sylXrfS in service spop Jun 21 14:23:12 minidspshd volumio[688]: SPOTIFY: EXPLODING URI:spotify:track:260EW8FU6e45oZ6sylXrfS Jun 21 14:23:12 minidspshd volumio[688]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4SNPg0KDZ859vauVTaNg7i","service":"spop","name":"HOW DOES IT FEEL?","artist":"The Kid LAROI","album":"HOW DOES IT FEEL?","type":"song","duration":137,"albumart":"https://i.scdn.co/image/ab67616d0000b27326635c77bed7eb81e29fe1fa","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 21 14:23:12 minidspshd volumio[688]: info: Exploding uri spotify:track:47w21Lurejb4n3r09H19Fz in service spop Jun 21 14:23:12 minidspshd volumio[688]: SPOTIFY: EXPLODING URI:spotify:track:47w21Lurejb4n3r09H19Fz Jun 21 14:23:12 minidspshd volumio[688]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6CBurTHmYJhIcDD72Qgjnm","service":"spop","name":"Close to you","artist":"PinkPantheress","album":"Close to you","type":"song","duration":103,"albumart":"https://i.scdn.co/image/ab67616d0000b273ee1d2c0d03580fbc6efcc1fd","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 21 14:23:12 minidspshd volumio[688]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3K5bLOU8pMGrDsPCfdL25g","service":"spop","name":"Wipe your tears","artist":"Sam Austins","album":"The woods, vol. 1","type":"song","duration":156,"albumart":"https://i.scdn.co/image/ab67616d0000b273e78a3958e5c70061098b24ed","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 21 14:23:12 minidspshd volumio[688]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1UlkpIKiVchDMB03AN6LmT","service":"spop","name":"Wait So Long","artist":"Swedish House Mafia","album":"Wait So Long","type":"song","duration":199,"albumart":"https://i.scdn.co/image/ab67616d0000b273dce44c98c297401176d580b3","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 21 14:23:12 minidspshd volumio[688]: info: Exploding uri spotify:track:2XbsqBrOdYjm0OLBEepID7 in service spop Jun 21 14:23:12 minidspshd volumio[688]: SPOTIFY: EXPLODING URI:spotify:track:2XbsqBrOdYjm0OLBEepID7 Jun 21 14:23:12 minidspshd volumio[688]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3zgZgaTkhrEhP8isvTw4Fr","service":"spop","name":"New Country (feat. Blake Shelton)","artist":"Noah Cyrus","album":"New Country (feat. Blake Shelton)","type":"song","duration":198,"albumart":"https://i.scdn.co/image/ab67616d0000b273ab95c690a0c8092428668c3b","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 21 14:23:12 minidspshd volumio[688]: info: Exploding uri spotify:track:4R7VfFjWXa62I3nDmiwAso in service spop Jun 21 14:23:12 minidspshd volumio[688]: SPOTIFY: EXPLODING URI:spotify:track:4R7VfFjWXa62I3nDmiwAso Jun 21 14:23:12 minidspshd volumio[688]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7v5VghHzM0iIoSQXGuZNzb","service":"spop","name":"S.M.O.","artist":"Amaarae","album":"S.M.O.","type":"song","duration":270,"albumart":"https://i.scdn.co/image/ab67616d0000b273b18bc4ae967963386185b437","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 21 14:23:12 minidspshd volumio[688]: info: Exploding uri spotify:track:12wvLk3fOmOonVmH0TtQ8L in service spop Jun 21 14:23:12 minidspshd volumio[688]: SPOTIFY: EXPLODING URI:spotify:track:12wvLk3fOmOonVmH0TtQ8L Jun 21 14:23:12 minidspshd volumio[688]: info: Exploding uri spotify:track:4kd3HIkMbwO4sVgkYkrBGo in service spop Jun 21 14:23:12 minidspshd volumio[688]: SPOTIFY: EXPLODING URI:spotify:track:4kd3HIkMbwO4sVgkYkrBGo Jun 21 14:23:12 minidspshd volumio[688]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0TeyADr2CzTOdwfsZCKn3c","service":"spop","name":"Voices","artist":"Gucci Mane","album":"Voices / Psycho","type":"song","duration":216,"albumart":"https://i.scdn.co/image/ab67616d0000b273a7c32ee90e5454bc072f10f3","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 21 14:23:12 minidspshd volumio[688]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:260EW8FU6e45oZ6sylXrfS","service":"spop","name":"Where To Start","artist":"Wale","album":"Where To Start","type":"song","duration":214,"albumart":"https://i.scdn.co/image/ab67616d0000b2734b08aac4bd9dbc82759aaf3a","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 21 14:23:12 minidspshd volumio[688]: info: Exploding uri spotify:track:1xOqGUkyxGQRdCvGpvWKmL in service spop Jun 21 14:23:12 minidspshd volumio[688]: SPOTIFY: EXPLODING URI:spotify:track:1xOqGUkyxGQRdCvGpvWKmL Jun 21 14:23:12 minidspshd volumio[688]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:47w21Lurejb4n3r09H19Fz","service":"spop","name":"Is Everybody Having Fun? (feat. rhys from the sticks)","artist":"John Summit","album":"Is Everybody Having Fun? (feat. rhys from the sticks)","type":"song","duration":169,"albumart":"https://i.scdn.co/image/ab67616d0000b273696dff7477ae55786d14cc79","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 21 14:23:12 minidspshd volumio[688]: info: Exploding uri spotify:track:1qHDg5ObxDpRZjoqPQGIyK in service spop Jun 21 14:23:12 minidspshd volumio[688]: SPOTIFY: EXPLODING URI:spotify:track:1qHDg5ObxDpRZjoqPQGIyK Jun 21 14:23:12 minidspshd volumio[688]: info: Exploding uri spotify:track:6Df0RNShcnfIJmrRoJ6Gc9 in service spop Jun 21 14:23:12 minidspshd volumio[688]: SPOTIFY: EXPLODING URI:spotify:track:6Df0RNShcnfIJmrRoJ6Gc9 Jun 21 14:23:12 minidspshd volumio[688]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2XbsqBrOdYjm0OLBEepID7","service":"spop","name":"Universidad","artist":"TINI","album":"Universidad","type":"song","duration":156,"albumart":"https://i.scdn.co/image/ab67616d0000b2739dc31ff1769a07ce6578890e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 21 14:23:12 minidspshd volumio[688]: info: Exploding uri spotify:track:13tMf761hDpFCGUiSZcNhk in service spop Jun 21 14:23:12 minidspshd volumio[688]: SPOTIFY: EXPLODING URI:spotify:track:13tMf761hDpFCGUiSZcNhk Jun 21 14:23:12 minidspshd volumio[688]: info: Exploding uri spotify:track:22CKFavEurPuJJsOFaobac in service spop Jun 21 14:23:12 minidspshd volumio[688]: SPOTIFY: EXPLODING URI:spotify:track:22CKFavEurPuJJsOFaobac Jun 21 14:23:12 minidspshd volumio[688]: info: Exploding uri spotify:track:3f2MxvJB9kQYSJFADpwE0A in service spop Jun 21 14:23:12 minidspshd volumio[688]: SPOTIFY: EXPLODING URI:spotify:track:3f2MxvJB9kQYSJFADpwE0A Jun 21 14:23:12 minidspshd volumio[688]: info: Exploding uri spotify:track:5g3PPNIHL5yMci2pio9ZoI in service spop Jun 21 14:23:12 minidspshd volumio[688]: SPOTIFY: EXPLODING URI:spotify:track:5g3PPNIHL5yMci2pio9ZoI Jun 21 14:23:12 minidspshd volumio[688]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4kd3HIkMbwO4sVgkYkrBGo","service":"spop","name":"Into Dust (Still Falling)","artist":"Four Tet","album":"Into Dust (Still Falling)","type":"song","duration":333,"albumart":"https://i.scdn.co/image/ab67616d0000b2733851add7a44c9ef68d0da29b","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 21 14:23:12 minidspshd volumio[688]: info: Exploding uri spotify:track:4EneW3YDPf0nWxcdIup9mW in service spop Jun 21 14:23:12 minidspshd volumio[688]: SPOTIFY: EXPLODING URI:spotify:track:4EneW3YDPf0nWxcdIup9mW Jun 21 14:23:12 minidspshd volumio[688]: info: Exploding uri spotify:track:00uXDC6A3RK2HJlTK6h0Ak in service spop Jun 21 14:23:12 minidspshd volumio[688]: SPOTIFY: EXPLODING URI:spotify:track:00uXDC6A3RK2HJlTK6h0Ak Jun 21 14:23:12 minidspshd volumio[688]: info: Exploding uri spotify:track:4mOWnjz30frv1pKMM6DNfv in service spop Jun 21 14:23:12 minidspshd volumio[688]: SPOTIFY: EXPLODING URI:spotify:track:4mOWnjz30frv1pKMM6DNfv Jun 21 14:23:12 minidspshd volumio[688]: info: Exploding uri spotify:track:5VdQP3CLYQrTOb9YZipDqC in service spop Jun 21 14:23:12 minidspshd volumio[688]: SPOTIFY: EXPLODING URI:spotify:track:5VdQP3CLYQrTOb9YZipDqC Jun 21 14:23:12 minidspshd volumio[688]: info: Preload queue cleared Jun 21 14:23:12 minidspshd volumio[688]: info: CoreCommandRouter::volumioAddQueueItems Jun 21 14:23:12 minidspshd volumio[688]: info: CoreStateMachine::addQueueItems Jun 21 14:23:12 minidspshd volumio[688]: info: CorePlayQueue::addQueueItems Jun 21 14:23:12 minidspshd volumio[688]: info: Preload queue cleared Jun 21 14:23:12 minidspshd volumio[688]: info: Adding Item to queue: spotify:track:6V7bxWg4mmuU4ILbYPQJvd Jun 21 14:23:12 minidspshd volumio[688]: info: Using cached record of: spotify:track:6V7bxWg4mmuU4ILbYPQJvd Jun 21 14:23:12 minidspshd volumio[688]: info: CoreCommandRouter::volumioPushQueue Jun 21 14:23:12 minidspshd volumio[688]: info: CorePlayQueue::saveQueue Jun 21 14:23:13 minidspshd volumio[688]: info: CoreStateMachine::updateTrackBlock Jun 21 14:23:13 minidspshd volumio[688]: info: CorePlayQueue::getTrackBlock Jun 21 14:23:13 minidspshd volumio[688]: info: CoreCommandRouter::volumioPlay Jun 21 14:23:13 minidspshd volumio[688]: info: CoreStateMachine::play index 77 Jun 21 14:23:13 minidspshd volumio[688]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 21 14:23:13 minidspshd volumio[688]: info: CoreStateMachine::stop Jun 21 14:23:13 minidspshd volumio[688]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 21 14:23:13 minidspshd volumio[688]: info: CoreStateMachine::play index undefined Jun 21 14:23:13 minidspshd volumio[688]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 21 14:23:13 minidspshd volumio[688]: info: CorePlayQueue::getTrack 77 Jun 21 14:23:13 minidspshd volumio[688]: info: CoreStateMachine::startPlaybackTimer Jun 21 14:23:13 minidspshd volumio[688]: info: CorePlayQueue::getTrack 77 Jun 21 14:23:13 minidspshd volumio[688]: info: CoreCommandRouter::volumioGetVisibleSources Jun 21 14:23:13 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 21 14:23:13 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Jun 21 14:23:13 minidspshd volumio[688]: info: [1750537393022] ControllerSpotify::clearAddPlayTrack Jun 21 14:23:13 minidspshd volumio[688]: info: Sending Spotify command with payload to local API: /player/play Jun 21 14:23:13 minidspshd volumio[688]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:23:13 minidspshd volumio[688]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1qHDg5ObxDpRZjoqPQGIyK","service":"spop","name":"Sycamore Tree","artist":"Khamari","album":"Sycamore Tree","type":"song","duration":215,"albumart":"https://i.scdn.co/image/ab67616d0000b27340d3c857198c665543d4519c","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 21 14:23:13 minidspshd volumio[688]: info: Getting Spotify volume Jun 21 14:23:13 minidspshd volumio[688]: (node:688) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:23:13 minidspshd volumio[688]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Jun 21 14:23:13 minidspshd volumio[688]: (node:688) 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: 80) Jun 21 14:23:13 minidspshd volumio[688]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Jun 21 14:23:13 minidspshd volumio[688]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1xOqGUkyxGQRdCvGpvWKmL","service":"spop","name":"Gabriela","artist":"KATSEYE","album":"Gabriela","type":"song","duration":197,"albumart":"https://i.scdn.co/image/ab67616d0000b2731f50fc82d780d1d935bbddd7","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 21 14:23:13 minidspshd volumio[688]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5g3PPNIHL5yMci2pio9ZoI","service":"spop","name":"Now and at the Hour of Our Death (feat. BONES)","artist":"$uicideboy$","album":"Now and at the Hour of Our Death (feat. BONES)","type":"song","duration":254,"albumart":"https://i.scdn.co/image/ab67616d0000b273136bd2c2a969bfa7a49e9c0f","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 21 14:23:13 minidspshd volumio[688]: info: CoreCommandRouter::volumioGetState Jun 21 14:23:13 minidspshd volumio[688]: info: CorePlayQueue::getTrack 77 Jun 21 14:23:13 minidspshd volumio[688]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4R7VfFjWXa62I3nDmiwAso","service":"spop","name":"Wound Up Here (By Holdin On)","artist":"Wednesday","album":"Wound Up Here (By Holdin On)","type":"song","duration":208,"albumart":"https://i.scdn.co/image/ab67616d0000b2735520fba0a406bed4c5382b7a","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 21 14:23:13 minidspshd volumio[688]: SPOTIFY: RECEIVED VOLUMIO VOLUME 77 Jun 21 14:23:13 minidspshd volumio[688]: info: Initializing connection to go-librespot Websocket Jun 21 14:23:13 minidspshd volumio[688]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:12wvLk3fOmOonVmH0TtQ8L","service":"spop","name":"Next To You","artist":"Erykah Badu","album":"Next To You","type":"song","duration":245,"albumart":"https://i.scdn.co/image/ab67616d0000b273073611e9a9c43403954457ce","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 21 14:23:13 minidspshd volumio[688]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:23:13 minidspshd volumio[688]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6Df0RNShcnfIJmrRoJ6Gc9","service":"spop","name":"Unravelling","artist":"Muse","album":"Unravelling","type":"song","duration":238,"albumart":"https://i.scdn.co/image/ab67616d0000b273fa20898960adebc321cf7342","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 21 14:23:13 minidspshd volumio[688]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:22CKFavEurPuJJsOFaobac","service":"spop","name":"99","artist":"Noah Rinker","album":"Burning Daylight","type":"song","duration":201,"albumart":"https://i.scdn.co/image/ab67616d0000b273882ff79f2886296e5b5cf3bb","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 21 14:23:13 minidspshd volumio[688]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3f2MxvJB9kQYSJFADpwE0A","service":"spop","name":"Just for Tonight","artist":"Rocco","album":"Skin & Bone","type":"song","duration":163,"albumart":"https://i.scdn.co/image/ab67616d0000b27360326ad783e8c7bc0a82b971","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 21 14:23:13 minidspshd volumio[688]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:13tMf761hDpFCGUiSZcNhk","service":"spop","name":"You Still Got It","artist":"Brett Young","album":"2.0","type":"song","duration":207,"albumart":"https://i.scdn.co/image/ab67616d0000b2736b2705f3d745465038982b28","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 21 14:23:13 minidspshd volumio[688]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4EneW3YDPf0nWxcdIup9mW","service":"spop","name":"Excuse Me","artist":"PLUTO","album":"BOTH WAYS","type":"song","duration":114,"albumart":"https://i.scdn.co/image/ab67616d0000b273d1acdc0a5598564d3c610b0d","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 21 14:23:13 minidspshd volumio[688]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:00uXDC6A3RK2HJlTK6h0Ak","service":"spop","name":"Luvaluvah","artist":"Olamide","album":"Olamidé","type":"song","duration":170,"albumart":"https://i.scdn.co/image/ab67616d0000b2734de99a77f4f4446a4bd0f155","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 21 14:23:13 minidspshd volumio[688]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4mOWnjz30frv1pKMM6DNfv","service":"spop","name":"Bonde do Brunão","artist":"Bruno Mars","album":"Bonde do Brunão","type":"song","duration":57,"albumart":"https://i.scdn.co/image/ab67616d0000b273613f87e023e5c44ad32b8263","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 21 14:23:13 minidspshd volumio[688]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5VdQP3CLYQrTOb9YZipDqC","service":"spop","name":"I'm in Love","artist":"S.G. Goodman","album":"Planting by the Signs","type":"song","duration":222,"albumart":"https://i.scdn.co/image/ab67616d0000b273a0e56261f8b5c8fe852e0e5c","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jun 21 14:23:13 minidspshd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 21 14:23:13 minidspshd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 247. Jun 21 14:23:13 minidspshd systemd[1]: Stopped go-librespot Daemon. Jun 21 14:23:13 minidspshd systemd[1]: Started go-librespot Daemon. Jun 21 14:23:13 minidspshd go-librespot[4233]: go-librespot daemon starting... Jun 21 14:23:13 minidspshd go-librespot[4233]: time="2025-06-21T14:23:13-06:00" level=info msg="running go-librespot 0.2.0" Jun 21 14:23:13 minidspshd go-librespot[4233]: time="2025-06-21T14:23:13-06:00" level=debug msg="app state loaded" Jun 21 14:23:13 minidspshd go-librespot[4233]: time="2025-06-21T14:23:13-06:00" level=debug msg="stored credentials not found" Jun 21 14:23:13 minidspshd go-librespot[4233]: time="2025-06-21T14:23:13-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 21 14:23:13 minidspshd go-librespot[4233]: time="2025-06-21T14:23:13-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 21 14:23:13 minidspshd go-librespot[4233]: time="2025-06-21T14:23:13-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 21 14:23:13 minidspshd go-librespot[4233]: time="2025-06-21T14:23:13-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 21 14:23:13 minidspshd go-librespot[4233]: time="2025-06-21T14:23:13-06:00" level=info msg="zeroconf server listening on port 36173" Jun 21 14:23:14 minidspshd go-librespot[4233]: time="2025-06-21T14:23:14-06:00" level=debug msg="obtained new client token: AACLnNcTvHFHYIwk7osi+4gNlDlCgXaNwdaczCa/C17KNpfkRYSa/HGZEzTMqXRTtiVv473x7HzbtZWdZxZk+euAHxJV3fUVlOQSwvcn2/rswXTaGvB05i/ofOu46FiIdu7wB1DPWsSdv6QsoQsI54V5DQmrBTk0boMa2Nx7oQ2700KOIgyHJlYoDNzeWANnP9EmeRm6E9DHNS6bFFkKiLMdgu23LBFMT/cm6rghMt0eo3QIwcGF" Jun 21 14:23:14 minidspshd go-librespot[4233]: time="2025-06-21T14:23:14-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jun 21 14:23:14 minidspshd go-librespot[4233]: time="2025-06-21T14:23:14-06:00" level=debug msg="completed keyexchange" Jun 21 14:23:14 minidspshd go-librespot[4233]: time="2025-06-21T14:23:14-06:00" level=debug msg="completed challenge" Jun 21 14:23:14 minidspshd go-librespot[4233]: time="2025-06-21T14:23:14-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 21 14:23:14 minidspshd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 21 14:23:14 minidspshd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 21 14:23:16 minidspshd volumio[688]: info: Initializing connection to go-librespot Websocket Jun 21 14:23:16 minidspshd volumio[688]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:23:17 minidspshd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 21 14:23:17 minidspshd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 248. Jun 21 14:23:17 minidspshd systemd[1]: Stopped go-librespot Daemon. Jun 21 14:23:17 minidspshd systemd[1]: Started go-librespot Daemon. Jun 21 14:23:17 minidspshd go-librespot[4279]: go-librespot daemon starting... Jun 21 14:23:17 minidspshd go-librespot[4279]: time="2025-06-21T14:23:17-06:00" level=info msg="running go-librespot 0.2.0" Jun 21 14:23:17 minidspshd go-librespot[4279]: time="2025-06-21T14:23:17-06:00" level=debug msg="app state loaded" Jun 21 14:23:17 minidspshd go-librespot[4279]: time="2025-06-21T14:23:17-06:00" level=debug msg="stored credentials not found" Jun 21 14:23:17 minidspshd go-librespot[4279]: time="2025-06-21T14:23:17-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 21 14:23:17 minidspshd volumio[688]: info: Preload queue cleared Jun 21 14:23:17 minidspshd volumio[688]: info: CoreCommandRouter::volumioAddQueueItems Jun 21 14:23:17 minidspshd volumio[688]: info: CoreStateMachine::addQueueItems Jun 21 14:23:17 minidspshd volumio[688]: info: CorePlayQueue::addQueueItems Jun 21 14:23:17 minidspshd volumio[688]: info: Preload queue cleared Jun 21 14:23:17 minidspshd volumio[688]: info: Adding Item to queue: spotify:track:6V7bxWg4mmuU4ILbYPQJvd Jun 21 14:23:17 minidspshd volumio[688]: info: Using cached record of: spotify:track:6V7bxWg4mmuU4ILbYPQJvd Jun 21 14:23:17 minidspshd volumio[688]: info: CoreCommandRouter::volumioPushQueue Jun 21 14:23:17 minidspshd volumio[688]: info: CorePlayQueue::saveQueue Jun 21 14:23:17 minidspshd volumio[688]: info: CoreStateMachine::updateTrackBlock Jun 21 14:23:17 minidspshd volumio[688]: info: CorePlayQueue::getTrackBlock Jun 21 14:23:17 minidspshd volumio[688]: info: CoreCommandRouter::volumioPlay Jun 21 14:23:17 minidspshd volumio[688]: info: CoreStateMachine::play index 77 Jun 21 14:23:17 minidspshd volumio[688]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 21 14:23:17 minidspshd volumio[688]: info: CoreStateMachine::stop Jun 21 14:23:17 minidspshd volumio[688]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 21 14:23:17 minidspshd volumio[688]: info: CoreStateMachine::play index undefined Jun 21 14:23:17 minidspshd volumio[688]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 21 14:23:17 minidspshd volumio[688]: info: CorePlayQueue::getTrack 77 Jun 21 14:23:17 minidspshd volumio[688]: info: CoreStateMachine::startPlaybackTimer Jun 21 14:23:17 minidspshd volumio[688]: info: CorePlayQueue::getTrack 77 Jun 21 14:23:17 minidspshd volumio[688]: info: CoreCommandRouter::volumioGetVisibleSources Jun 21 14:23:17 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 21 14:23:17 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Jun 21 14:23:17 minidspshd volumio[688]: info: [1750537397723] ControllerSpotify::clearAddPlayTrack Jun 21 14:23:17 minidspshd volumio[688]: info: Sending Spotify command with payload to local API: /player/play Jun 21 14:23:18 minidspshd go-librespot[4279]: time="2025-06-21T14:23:18-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 21 14:23:18 minidspshd go-librespot[4279]: time="2025-06-21T14:23:18-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 21 14:23:18 minidspshd go-librespot[4279]: time="2025-06-21T14:23:18-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 21 14:23:18 minidspshd go-librespot[4279]: time="2025-06-21T14:23:18-06:00" level=info msg="zeroconf server listening on port 43201" Jun 21 14:23:18 minidspshd go-librespot[4279]: time="2025-06-21T14:23:18-06:00" level=debug msg="obtained new client token: AACaI8uba2T/Jm/h9HUbGvynz7Nbq3LLlZI+xaaiHteOd5XD9LSr3NW3wvqKYTGeDUlSAzuPziXjLENHEuoh/5qmqd6/mETHLRh1L9a0Tlg2po2JdtjMdo7jwfKswAhsXAyLHnDcEzf1dRxHr460l84dZy9XK/ijPIVBPUwjJ4ZrJW0/U3F1uhSHCzTd9zGRYX4ARwjheO0N2moIKHe1HjpMPNivELd0rOZLjeWWu3uK0kUYIajf" Jun 21 14:23:18 minidspshd go-librespot[4279]: time="2025-06-21T14:23:18-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jun 21 14:23:18 minidspshd go-librespot[4279]: time="2025-06-21T14:23:18-06:00" level=debug msg="completed keyexchange" Jun 21 14:23:18 minidspshd go-librespot[4279]: time="2025-06-21T14:23:18-06:00" level=debug msg="completed challenge" Jun 21 14:23:18 minidspshd go-librespot[4279]: time="2025-06-21T14:23:18-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 21 14:23:18 minidspshd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 21 14:23:18 minidspshd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 21 14:23:18 minidspshd volumio[688]: error: Failed to send command to Spotify local API: /player/play: Error: socket hang up Jun 21 14:23:19 minidspshd volumio[688]: info: Preload queue cleared Jun 21 14:23:19 minidspshd volumio[688]: info: CoreCommandRouter::volumioAddQueueItems Jun 21 14:23:19 minidspshd volumio[688]: info: CoreStateMachine::addQueueItems Jun 21 14:23:19 minidspshd volumio[688]: info: CorePlayQueue::addQueueItems Jun 21 14:23:19 minidspshd volumio[688]: info: Preload queue cleared Jun 21 14:23:19 minidspshd volumio[688]: info: Adding Item to queue: spotify:track:6V7bxWg4mmuU4ILbYPQJvd Jun 21 14:23:19 minidspshd volumio[688]: info: Using cached record of: spotify:track:6V7bxWg4mmuU4ILbYPQJvd Jun 21 14:23:19 minidspshd volumio[688]: info: CoreCommandRouter::volumioPushQueue Jun 21 14:23:19 minidspshd volumio[688]: info: CorePlayQueue::saveQueue Jun 21 14:23:19 minidspshd volumio[688]: info: CoreStateMachine::updateTrackBlock Jun 21 14:23:19 minidspshd volumio[688]: info: CorePlayQueue::getTrackBlock Jun 21 14:23:19 minidspshd volumio[688]: info: CoreCommandRouter::volumioPlay Jun 21 14:23:19 minidspshd volumio[688]: info: CoreStateMachine::play index 77 Jun 21 14:23:19 minidspshd volumio[688]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 21 14:23:19 minidspshd volumio[688]: info: CoreStateMachine::stop Jun 21 14:23:19 minidspshd volumio[688]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 21 14:23:19 minidspshd volumio[688]: info: CoreStateMachine::play index undefined Jun 21 14:23:19 minidspshd volumio[688]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 21 14:23:19 minidspshd volumio[688]: info: CorePlayQueue::getTrack 77 Jun 21 14:23:19 minidspshd volumio[688]: info: CoreStateMachine::startPlaybackTimer Jun 21 14:23:19 minidspshd volumio[688]: info: CorePlayQueue::getTrack 77 Jun 21 14:23:19 minidspshd volumio[688]: info: CoreCommandRouter::volumioGetVisibleSources Jun 21 14:23:19 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 21 14:23:19 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Jun 21 14:23:19 minidspshd volumio[688]: info: [1750537399234] ControllerSpotify::clearAddPlayTrack Jun 21 14:23:19 minidspshd volumio[688]: info: Sending Spotify command with payload to local API: /player/play Jun 21 14:23:19 minidspshd volumio[688]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:23:19 minidspshd volumio[688]: info: Initializing connection to go-librespot Websocket Jun 21 14:23:19 minidspshd volumio[688]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:23:20 minidspshd volumio[688]: info: CoreCommandRouter::volumioPlay Jun 21 14:23:20 minidspshd volumio[688]: info: CoreStateMachine::play index undefined Jun 21 14:23:20 minidspshd volumio[688]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 21 14:23:20 minidspshd volumio[688]: info: CorePlayQueue::getTrack 77 Jun 21 14:23:20 minidspshd volumio[688]: info: CoreStateMachine::startPlaybackTimer Jun 21 14:23:20 minidspshd volumio[688]: info: CorePlayQueue::getTrack 77 Jun 21 14:23:20 minidspshd volumio[688]: info: CoreCommandRouter::volumioGetVisibleSources Jun 21 14:23:20 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 21 14:23:20 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Jun 21 14:23:20 minidspshd volumio[688]: info: [1750537400055] ControllerSpotify::clearAddPlayTrack Jun 21 14:23:20 minidspshd volumio[688]: info: Sending Spotify command with payload to local API: /player/play Jun 21 14:23:20 minidspshd volumio[688]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:23:20 minidspshd volumio[688]: info: CoreCommandRouter::volumioPlay Jun 21 14:23:20 minidspshd volumio[688]: info: CoreStateMachine::play index undefined Jun 21 14:23:20 minidspshd volumio[688]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 21 14:23:20 minidspshd volumio[688]: info: CorePlayQueue::getTrack 77 Jun 21 14:23:20 minidspshd volumio[688]: info: CoreStateMachine::startPlaybackTimer Jun 21 14:23:20 minidspshd volumio[688]: info: CorePlayQueue::getTrack 77 Jun 21 14:23:20 minidspshd volumio[688]: info: CoreCommandRouter::volumioGetVisibleSources Jun 21 14:23:20 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 21 14:23:20 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Jun 21 14:23:20 minidspshd volumio[688]: info: [1750537400990] ControllerSpotify::clearAddPlayTrack Jun 21 14:23:20 minidspshd volumio[688]: info: Sending Spotify command with payload to local API: /player/play Jun 21 14:23:20 minidspshd volumio[688]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:23:21 minidspshd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 21 14:23:21 minidspshd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 249. Jun 21 14:23:21 minidspshd systemd[1]: Stopped go-librespot Daemon. Jun 21 14:23:21 minidspshd systemd[1]: Started go-librespot Daemon. Jun 21 14:23:21 minidspshd go-librespot[4287]: go-librespot daemon starting... Jun 21 14:23:21 minidspshd go-librespot[4287]: time="2025-06-21T14:23:21-06:00" level=info msg="running go-librespot 0.2.0" Jun 21 14:23:21 minidspshd go-librespot[4287]: time="2025-06-21T14:23:21-06:00" level=debug msg="app state loaded" Jun 21 14:23:21 minidspshd go-librespot[4287]: time="2025-06-21T14:23:21-06:00" level=debug msg="stored credentials not found" Jun 21 14:23:21 minidspshd go-librespot[4287]: time="2025-06-21T14:23:21-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 21 14:23:22 minidspshd go-librespot[4287]: time="2025-06-21T14:23:22-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 21 14:23:22 minidspshd go-librespot[4287]: time="2025-06-21T14:23:22-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 21 14:23:22 minidspshd go-librespot[4287]: time="2025-06-21T14:23:22-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 21 14:23:22 minidspshd go-librespot[4287]: time="2025-06-21T14:23:22-06:00" level=info msg="zeroconf server listening on port 41917" Jun 21 14:23:22 minidspshd volumio[688]: info: Initializing connection to go-librespot Websocket Jun 21 14:23:22 minidspshd go-librespot[4287]: time="2025-06-21T14:23:22-06:00" level=debug msg="new websocket client" Jun 21 14:23:22 minidspshd volumio[688]: info: Connection to go-librespot Websocket established Jun 21 14:23:22 minidspshd go-librespot[4287]: time="2025-06-21T14:23:22-06:00" level=debug msg="obtained new client token: AACopnLg7MIA2Nf+QSWKGtaHFbJwZxhK9qk2L+gXP5WQMd//TAfP2oruMyqDxZQZhl9/2Bf9IuucPQh1PBA/Aqa0tiQ32Vvq4t0cZalD1affkBZzx2xxkbrOqoOskN/HB4YkbPLTCrWN9CJybISf/zIEoFVsdUPvUizggVn2VsJMG9k6SDZfu7kJNpLe2c9NbZGa21g8yHgWVOttk/pnA2H2WV0E0lR6P0GHhVIPa8YG4NlJMM0vMlA=" Jun 21 14:23:22 minidspshd go-librespot[4287]: time="2025-06-21T14:23:22-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jun 21 14:23:22 minidspshd go-librespot[4287]: time="2025-06-21T14:23:22-06:00" level=debug msg="completed keyexchange" Jun 21 14:23:22 minidspshd go-librespot[4287]: time="2025-06-21T14:23:22-06:00" level=debug msg="completed challenge" Jun 21 14:23:22 minidspshd go-librespot[4287]: time="2025-06-21T14:23:22-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 21 14:23:22 minidspshd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 21 14:23:22 minidspshd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 21 14:23:22 minidspshd volumio[688]: info: Connection to go-librespot Websocket closed Jun 21 14:23:23 minidspshd volumio[688]: info: CoreCommandRouter::volumioPlay Jun 21 14:23:23 minidspshd volumio[688]: info: CoreStateMachine::play index undefined Jun 21 14:23:23 minidspshd volumio[688]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 21 14:23:23 minidspshd volumio[688]: info: CorePlayQueue::getTrack 77 Jun 21 14:23:23 minidspshd volumio[688]: info: CoreStateMachine::startPlaybackTimer Jun 21 14:23:23 minidspshd volumio[688]: info: CorePlayQueue::getTrack 77 Jun 21 14:23:23 minidspshd volumio[688]: info: CoreCommandRouter::volumioGetVisibleSources Jun 21 14:23:23 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 21 14:23:23 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Jun 21 14:23:23 minidspshd volumio[688]: info: [1750537403724] ControllerSpotify::clearAddPlayTrack Jun 21 14:23:23 minidspshd volumio[688]: info: Sending Spotify command with payload to local API: /player/play Jun 21 14:23:23 minidspshd volumio[688]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:23:25 minidspshd volumio[688]: info: Getting Spotify volume Jun 21 14:23:25 minidspshd volumio[688]: (node:688) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:23:25 minidspshd volumio[688]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Jun 21 14:23:25 minidspshd volumio[688]: (node:688) 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: 81) Jun 21 14:23:25 minidspshd volumio[688]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Jun 21 14:23:25 minidspshd volumio[688]: info: CoreCommandRouter::volumioGetState Jun 21 14:23:25 minidspshd volumio[688]: info: CorePlayQueue::getTrack 77 Jun 21 14:23:25 minidspshd volumio[688]: SPOTIFY: RECEIVED VOLUMIO VOLUME 77 Jun 21 14:23:25 minidspshd volumio[688]: info: Initializing connection to go-librespot Websocket Jun 21 14:23:25 minidspshd volumio[688]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:23:25 minidspshd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 21 14:23:25 minidspshd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 250. Jun 21 14:23:25 minidspshd systemd[1]: Stopped go-librespot Daemon. Jun 21 14:23:25 minidspshd systemd[1]: Started go-librespot Daemon. Jun 21 14:23:25 minidspshd go-librespot[4295]: go-librespot daemon starting... Jun 21 14:23:26 minidspshd go-librespot[4295]: time="2025-06-21T14:23:26-06:00" level=info msg="running go-librespot 0.2.0" Jun 21 14:23:26 minidspshd go-librespot[4295]: time="2025-06-21T14:23:26-06:00" level=debug msg="app state loaded" Jun 21 14:23:26 minidspshd go-librespot[4295]: time="2025-06-21T14:23:26-06:00" level=debug msg="stored credentials not found" Jun 21 14:23:26 minidspshd go-librespot[4295]: time="2025-06-21T14:23:26-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 21 14:23:26 minidspshd go-librespot[4295]: time="2025-06-21T14:23:26-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 21 14:23:26 minidspshd go-librespot[4295]: time="2025-06-21T14:23:26-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 21 14:23:26 minidspshd go-librespot[4295]: time="2025-06-21T14:23:26-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 21 14:23:26 minidspshd go-librespot[4295]: time="2025-06-21T14:23:26-06:00" level=info msg="zeroconf server listening on port 34583" Jun 21 14:23:26 minidspshd go-librespot[4295]: time="2025-06-21T14:23:26-06:00" level=debug msg="obtained new client token: AABRMcNf7gq/ZzUVNa/XZ6CEzBaBDQKY2QjBp2lv0D7Hu+bZbvdEf05EWWXwk+6N8hCv1vCQBys0yFoOQvw2t751fsXQD6K9ypHYVHIwsOzORKBz8/4a+56om55M6r4qp+Mz0kqvVb3jmGMWR4jEfZn3zxJL6L/WrIaA2SVthsUqzy0su56JugJbi/7qj8XGp7niRZLC4aqdcbNDbwSlAYiVnrjEMnz8OLEuzm7kJDPEdUOHzNd7CUw=" Jun 21 14:23:26 minidspshd volumio[688]: info: Preload queue cleared Jun 21 14:23:26 minidspshd volumio[688]: info: CoreCommandRouter::volumioAddQueueItems Jun 21 14:23:26 minidspshd volumio[688]: info: CoreStateMachine::addQueueItems Jun 21 14:23:26 minidspshd volumio[688]: info: CorePlayQueue::addQueueItems Jun 21 14:23:26 minidspshd volumio[688]: info: Preload queue cleared Jun 21 14:23:26 minidspshd volumio[688]: info: Adding Item to queue: spotify:track:6V7bxWg4mmuU4ILbYPQJvd Jun 21 14:23:26 minidspshd volumio[688]: info: Using cached record of: spotify:track:6V7bxWg4mmuU4ILbYPQJvd Jun 21 14:23:26 minidspshd volumio[688]: info: CoreCommandRouter::volumioPushQueue Jun 21 14:23:26 minidspshd volumio[688]: info: CorePlayQueue::saveQueue Jun 21 14:23:26 minidspshd volumio[688]: info: CoreStateMachine::updateTrackBlock Jun 21 14:23:26 minidspshd volumio[688]: info: CorePlayQueue::getTrackBlock Jun 21 14:23:26 minidspshd volumio[688]: info: CoreCommandRouter::volumioPlay Jun 21 14:23:26 minidspshd volumio[688]: info: CoreStateMachine::play index 77 Jun 21 14:23:26 minidspshd volumio[688]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 21 14:23:26 minidspshd volumio[688]: info: CoreStateMachine::stop Jun 21 14:23:26 minidspshd volumio[688]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 21 14:23:26 minidspshd volumio[688]: info: CoreStateMachine::play index undefined Jun 21 14:23:26 minidspshd volumio[688]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 21 14:23:26 minidspshd volumio[688]: info: CorePlayQueue::getTrack 77 Jun 21 14:23:26 minidspshd volumio[688]: info: CoreStateMachine::startPlaybackTimer Jun 21 14:23:26 minidspshd volumio[688]: info: CorePlayQueue::getTrack 77 Jun 21 14:23:26 minidspshd volumio[688]: info: CoreCommandRouter::volumioGetVisibleSources Jun 21 14:23:26 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 21 14:23:26 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Jun 21 14:23:26 minidspshd volumio[688]: info: [1750537406829] ControllerSpotify::clearAddPlayTrack Jun 21 14:23:26 minidspshd volumio[688]: info: Sending Spotify command with payload to local API: /player/play Jun 21 14:23:26 minidspshd go-librespot[4295]: time="2025-06-21T14:23:26-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jun 21 14:23:26 minidspshd go-librespot[4295]: time="2025-06-21T14:23:26-06:00" level=debug msg="completed keyexchange" Jun 21 14:23:26 minidspshd go-librespot[4295]: time="2025-06-21T14:23:26-06:00" level=debug msg="completed challenge" Jun 21 14:23:27 minidspshd go-librespot[4295]: time="2025-06-21T14:23:27-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 21 14:23:27 minidspshd volumio[688]: error: Failed to send command to Spotify local API: /player/play: Error: socket hang up Jun 21 14:23:27 minidspshd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 21 14:23:27 minidspshd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 21 14:23:28 minidspshd volumio[688]: info: Initializing connection to go-librespot Websocket Jun 21 14:23:28 minidspshd volumio[688]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:23:29 minidspshd volumio[688]: info: Preload queue cleared Jun 21 14:23:29 minidspshd volumio[688]: info: CoreCommandRouter::volumioAddQueueItems Jun 21 14:23:29 minidspshd volumio[688]: info: CoreStateMachine::addQueueItems Jun 21 14:23:29 minidspshd volumio[688]: info: CorePlayQueue::addQueueItems Jun 21 14:23:29 minidspshd volumio[688]: info: Preload queue cleared Jun 21 14:23:29 minidspshd volumio[688]: info: Adding Item to queue: spotify:track:7o3xJRQhpHRZ6IbyQX2xrp Jun 21 14:23:29 minidspshd volumio[688]: info: Using cached record of: spotify:track:7o3xJRQhpHRZ6IbyQX2xrp Jun 21 14:23:29 minidspshd volumio[688]: info: CoreCommandRouter::volumioPushQueue Jun 21 14:23:29 minidspshd volumio[688]: info: CorePlayQueue::saveQueue Jun 21 14:23:29 minidspshd volumio[688]: info: CoreStateMachine::updateTrackBlock Jun 21 14:23:29 minidspshd volumio[688]: info: CorePlayQueue::getTrackBlock Jun 21 14:23:29 minidspshd volumio[688]: info: CoreCommandRouter::volumioPlay Jun 21 14:23:29 minidspshd volumio[688]: info: CoreStateMachine::play index 78 Jun 21 14:23:29 minidspshd volumio[688]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 21 14:23:29 minidspshd volumio[688]: info: CoreStateMachine::stop Jun 21 14:23:29 minidspshd volumio[688]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 21 14:23:29 minidspshd volumio[688]: info: CoreStateMachine::play index undefined Jun 21 14:23:29 minidspshd volumio[688]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 21 14:23:29 minidspshd volumio[688]: info: CorePlayQueue::getTrack 78 Jun 21 14:23:29 minidspshd volumio[688]: info: CoreStateMachine::startPlaybackTimer Jun 21 14:23:29 minidspshd volumio[688]: info: CorePlayQueue::getTrack 78 Jun 21 14:23:29 minidspshd volumio[688]: info: CoreCommandRouter::volumioGetVisibleSources Jun 21 14:23:29 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 21 14:23:29 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Jun 21 14:23:29 minidspshd volumio[688]: info: [1750537409145] ControllerSpotify::clearAddPlayTrack Jun 21 14:23:29 minidspshd volumio[688]: info: Sending Spotify command with payload to local API: /player/play Jun 21 14:23:29 minidspshd volumio[688]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:23:30 minidspshd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 21 14:23:30 minidspshd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 251. Jun 21 14:23:30 minidspshd systemd[1]: Stopped go-librespot Daemon. Jun 21 14:23:30 minidspshd systemd[1]: Started go-librespot Daemon. Jun 21 14:23:30 minidspshd go-librespot[4304]: go-librespot daemon starting... Jun 21 14:23:30 minidspshd go-librespot[4304]: time="2025-06-21T14:23:30-06:00" level=info msg="running go-librespot 0.2.0" Jun 21 14:23:30 minidspshd go-librespot[4304]: time="2025-06-21T14:23:30-06:00" level=debug msg="app state loaded" Jun 21 14:23:30 minidspshd go-librespot[4304]: time="2025-06-21T14:23:30-06:00" level=debug msg="stored credentials not found" Jun 21 14:23:30 minidspshd go-librespot[4304]: time="2025-06-21T14:23:30-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 21 14:23:30 minidspshd go-librespot[4304]: time="2025-06-21T14:23:30-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 21 14:23:30 minidspshd go-librespot[4304]: time="2025-06-21T14:23:30-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 21 14:23:30 minidspshd go-librespot[4304]: time="2025-06-21T14:23:30-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 21 14:23:30 minidspshd go-librespot[4304]: time="2025-06-21T14:23:30-06:00" level=info msg="zeroconf server listening on port 46567" Jun 21 14:23:30 minidspshd go-librespot[4304]: time="2025-06-21T14:23:30-06:00" level=debug msg="obtained new client token: AAAw8tF+vOFObmh8mosT8DKXBo4j6ay8bdPUH+IUKz7iGVN3vpogqP0pukTwQu1c3aRrxlt0CkgR1eqYFjKU2kwDt/K3cg0GIy/GAvKH18Y3uYxepr8KgURXxEYZMnHuRaq4FM8OZteiFCw8puR8Wp3USqiVxuvi3ZRNyof/mGH2rVMG4CBJt4N32ZAD8TGo5VrzyHIAMIXkiA8eOYdGuNGiNDzjn9Hj5Lq1FTSXHFjLLyhDqrJwBu8=" Jun 21 14:23:30 minidspshd go-librespot[4304]: time="2025-06-21T14:23:30-06:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused" Jun 21 14:23:31 minidspshd go-librespot[4304]: time="2025-06-21T14:23:31-06:00" level=debug msg="connected to ap-guc3.spotify.com:443" Jun 21 14:23:31 minidspshd go-librespot[4304]: time="2025-06-21T14:23:31-06:00" level=debug msg="completed keyexchange" Jun 21 14:23:31 minidspshd go-librespot[4304]: time="2025-06-21T14:23:31-06:00" level=debug msg="completed challenge" Jun 21 14:23:31 minidspshd go-librespot[4304]: time="2025-06-21T14:23:31-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 21 14:23:31 minidspshd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 21 14:23:31 minidspshd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 21 14:23:31 minidspshd volumio[688]: info: Initializing connection to go-librespot Websocket Jun 21 14:23:31 minidspshd volumio[688]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:23:31 minidspshd volumio[688]: info: Preload queue cleared Jun 21 14:23:31 minidspshd volumio[688]: info: CoreCommandRouter::volumioAddQueueItems Jun 21 14:23:31 minidspshd volumio[688]: info: CoreStateMachine::addQueueItems Jun 21 14:23:31 minidspshd volumio[688]: info: CorePlayQueue::addQueueItems Jun 21 14:23:31 minidspshd volumio[688]: info: Preload queue cleared Jun 21 14:23:31 minidspshd volumio[688]: info: Adding Item to queue: spotify:track:64zQbQTwu4ppBEfWyhst9t Jun 21 14:23:31 minidspshd volumio[688]: info: Using cached record of: spotify:track:64zQbQTwu4ppBEfWyhst9t Jun 21 14:23:31 minidspshd volumio[688]: info: CoreCommandRouter::volumioPushQueue Jun 21 14:23:31 minidspshd volumio[688]: info: CorePlayQueue::saveQueue Jun 21 14:23:31 minidspshd volumio[688]: info: CoreStateMachine::updateTrackBlock Jun 21 14:23:31 minidspshd volumio[688]: info: CorePlayQueue::getTrackBlock Jun 21 14:23:31 minidspshd volumio[688]: info: CoreCommandRouter::volumioPlay Jun 21 14:23:31 minidspshd volumio[688]: info: CoreStateMachine::play index 79 Jun 21 14:23:31 minidspshd volumio[688]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 21 14:23:31 minidspshd volumio[688]: info: CoreStateMachine::stop Jun 21 14:23:31 minidspshd volumio[688]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 21 14:23:31 minidspshd volumio[688]: info: CoreStateMachine::play index undefined Jun 21 14:23:31 minidspshd volumio[688]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 21 14:23:31 minidspshd volumio[688]: info: CorePlayQueue::getTrack 79 Jun 21 14:23:31 minidspshd volumio[688]: info: CoreStateMachine::startPlaybackTimer Jun 21 14:23:31 minidspshd volumio[688]: info: CorePlayQueue::getTrack 79 Jun 21 14:23:31 minidspshd volumio[688]: info: CoreCommandRouter::volumioGetVisibleSources Jun 21 14:23:31 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 21 14:23:31 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Jun 21 14:23:31 minidspshd volumio[688]: info: [1750537411852] ControllerSpotify::clearAddPlayTrack Jun 21 14:23:31 minidspshd volumio[688]: info: Sending Spotify command with payload to local API: /player/play Jun 21 14:23:31 minidspshd volumio[688]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:23:32 minidspshd volumio[688]: info: Preload queue cleared Jun 21 14:23:32 minidspshd volumio[688]: info: CoreCommandRouter::volumioAddQueueItems Jun 21 14:23:32 minidspshd volumio[688]: info: CoreStateMachine::addQueueItems Jun 21 14:23:32 minidspshd volumio[688]: info: CorePlayQueue::addQueueItems Jun 21 14:23:32 minidspshd volumio[688]: info: Preload queue cleared Jun 21 14:23:32 minidspshd volumio[688]: info: Adding Item to queue: spotify:track:64zQbQTwu4ppBEfWyhst9t Jun 21 14:23:32 minidspshd volumio[688]: info: Using cached record of: spotify:track:64zQbQTwu4ppBEfWyhst9t Jun 21 14:23:32 minidspshd volumio[688]: info: CoreCommandRouter::volumioPushQueue Jun 21 14:23:32 minidspshd volumio[688]: info: CorePlayQueue::saveQueue Jun 21 14:23:32 minidspshd volumio[688]: info: CoreStateMachine::updateTrackBlock Jun 21 14:23:32 minidspshd volumio[688]: info: CorePlayQueue::getTrackBlock Jun 21 14:23:32 minidspshd volumio[688]: info: CoreCommandRouter::volumioPlay Jun 21 14:23:32 minidspshd volumio[688]: info: CoreStateMachine::play index 79 Jun 21 14:23:32 minidspshd volumio[688]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 21 14:23:32 minidspshd volumio[688]: info: CoreStateMachine::stop Jun 21 14:23:32 minidspshd volumio[688]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 21 14:23:32 minidspshd volumio[688]: info: CoreStateMachine::play index undefined Jun 21 14:23:32 minidspshd volumio[688]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 21 14:23:32 minidspshd volumio[688]: info: CorePlayQueue::getTrack 79 Jun 21 14:23:32 minidspshd volumio[688]: info: CoreStateMachine::startPlaybackTimer Jun 21 14:23:32 minidspshd volumio[688]: info: CorePlayQueue::getTrack 79 Jun 21 14:23:32 minidspshd volumio[688]: info: CoreCommandRouter::volumioGetVisibleSources Jun 21 14:23:32 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 21 14:23:32 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Jun 21 14:23:32 minidspshd volumio[688]: info: [1750537412366] ControllerSpotify::clearAddPlayTrack Jun 21 14:23:32 minidspshd volumio[688]: info: Sending Spotify command with payload to local API: /player/play Jun 21 14:23:32 minidspshd volumio[688]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:23:33 minidspshd volumio[688]: info: CoreCommandRouter::volumioPlay Jun 21 14:23:33 minidspshd volumio[688]: info: CoreStateMachine::play index undefined Jun 21 14:23:33 minidspshd volumio[688]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 21 14:23:33 minidspshd volumio[688]: info: CorePlayQueue::getTrack 79 Jun 21 14:23:33 minidspshd volumio[688]: info: CoreStateMachine::startPlaybackTimer Jun 21 14:23:33 minidspshd volumio[688]: info: CorePlayQueue::getTrack 79 Jun 21 14:23:33 minidspshd volumio[688]: info: CoreCommandRouter::volumioGetVisibleSources Jun 21 14:23:33 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 21 14:23:33 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Jun 21 14:23:33 minidspshd volumio[688]: info: [1750537413684] ControllerSpotify::clearAddPlayTrack Jun 21 14:23:33 minidspshd volumio[688]: info: Sending Spotify command with payload to local API: /player/play Jun 21 14:23:33 minidspshd volumio[688]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:23:34 minidspshd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 21 14:23:34 minidspshd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 252. Jun 21 14:23:34 minidspshd systemd[1]: Stopped go-librespot Daemon. Jun 21 14:23:34 minidspshd systemd[1]: Started go-librespot Daemon. Jun 21 14:23:34 minidspshd go-librespot[4313]: go-librespot daemon starting... Jun 21 14:23:34 minidspshd go-librespot[4313]: time="2025-06-21T14:23:34-06:00" level=info msg="running go-librespot 0.2.0" Jun 21 14:23:34 minidspshd go-librespot[4313]: time="2025-06-21T14:23:34-06:00" level=debug msg="app state loaded" Jun 21 14:23:34 minidspshd go-librespot[4313]: time="2025-06-21T14:23:34-06:00" level=debug msg="stored credentials not found" Jun 21 14:23:34 minidspshd go-librespot[4313]: time="2025-06-21T14:23:34-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 21 14:23:34 minidspshd go-librespot[4313]: time="2025-06-21T14:23:34-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jun 21 14:23:34 minidspshd go-librespot[4313]: time="2025-06-21T14:23:34-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jun 21 14:23:34 minidspshd go-librespot[4313]: time="2025-06-21T14:23:34-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jun 21 14:23:34 minidspshd go-librespot[4313]: time="2025-06-21T14:23:34-06:00" level=info msg="zeroconf server listening on port 46845" Jun 21 14:23:34 minidspshd volumio[688]: info: Initializing connection to go-librespot Websocket Jun 21 14:23:34 minidspshd go-librespot[4313]: time="2025-06-21T14:23:34-06:00" level=debug msg="new websocket client" Jun 21 14:23:34 minidspshd volumio[688]: info: Connection to go-librespot Websocket established Jun 21 14:23:34 minidspshd go-librespot[4313]: time="2025-06-21T14:23:34-06:00" level=debug msg="obtained new client token: AABjoaa0d+pRrL03NvcgTIo5D0Q8jQrGzfFjvWc+r7rY5risuie2NCMupZpy70RKnuoBIR/vhPqktSWhFKqBzsPHFNvqU5bm4KI3W073Pg3DK1Hx9q7i3OYyaBUiMObHgosrLJPHdPsScnAIucLQDnvWbF1lEppTg9aVw95eMSKuPWRgUIXLY2MvtSWvohyqEyUm624FRjwXXGhr9ElK8Rgzwu+J7A7KilWhvt2jaDWFEijjp1+hmns=" Jun 21 14:23:35 minidspshd go-librespot[4313]: time="2025-06-21T14:23:35-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jun 21 14:23:35 minidspshd go-librespot[4313]: time="2025-06-21T14:23:35-06:00" level=debug msg="completed keyexchange" Jun 21 14:23:35 minidspshd go-librespot[4313]: time="2025-06-21T14:23:35-06:00" level=debug msg="completed challenge" Jun 21 14:23:35 minidspshd go-librespot[4313]: time="2025-06-21T14:23:35-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 21 14:23:35 minidspshd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 21 14:23:35 minidspshd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 21 14:23:35 minidspshd volumio[688]: info: Connection to go-librespot Websocket closed Jun 21 14:23:35 minidspshd volumio[688]: info: CoreCommandRouter::volumioPlay Jun 21 14:23:35 minidspshd volumio[688]: info: CoreStateMachine::play index undefined Jun 21 14:23:35 minidspshd volumio[688]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 21 14:23:35 minidspshd volumio[688]: info: CorePlayQueue::getTrack 79 Jun 21 14:23:35 minidspshd volumio[688]: info: CoreStateMachine::startPlaybackTimer Jun 21 14:23:35 minidspshd volumio[688]: info: CorePlayQueue::getTrack 79 Jun 21 14:23:35 minidspshd volumio[688]: info: CoreCommandRouter::volumioGetVisibleSources Jun 21 14:23:35 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 21 14:23:35 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Jun 21 14:23:35 minidspshd volumio[688]: info: [1750537415973] ControllerSpotify::clearAddPlayTrack Jun 21 14:23:35 minidspshd volumio[688]: info: Sending Spotify command with payload to local API: /player/play Jun 21 14:23:35 minidspshd volumio[688]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:23:37 minidspshd volumio[688]: info: CoreCommandRouter::volumioPlay Jun 21 14:23:37 minidspshd volumio[688]: info: CoreStateMachine::play index undefined Jun 21 14:23:37 minidspshd volumio[688]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 21 14:23:37 minidspshd volumio[688]: info: CorePlayQueue::getTrack 79 Jun 21 14:23:37 minidspshd volumio[688]: info: CoreStateMachine::startPlaybackTimer Jun 21 14:23:37 minidspshd volumio[688]: info: CorePlayQueue::getTrack 79 Jun 21 14:23:37 minidspshd volumio[688]: info: CoreCommandRouter::volumioGetVisibleSources Jun 21 14:23:37 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 21 14:23:37 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Jun 21 14:23:37 minidspshd volumio[688]: info: [1750537417229] ControllerSpotify::clearAddPlayTrack Jun 21 14:23:37 minidspshd volumio[688]: info: Sending Spotify command with payload to local API: /player/play Jun 21 14:23:37 minidspshd volumio[688]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:23:37 minidspshd volumio[688]: info: Getting Spotify volume Jun 21 14:23:37 minidspshd volumio[688]: (node:688) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:23:37 minidspshd volumio[688]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Jun 21 14:23:37 minidspshd volumio[688]: (node:688) 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: 82) Jun 21 14:23:37 minidspshd volumio[688]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Jun 21 14:23:37 minidspshd volumio[688]: info: CoreCommandRouter::volumioGetState Jun 21 14:23:37 minidspshd volumio[688]: info: CorePlayQueue::getTrack 79 Jun 21 14:23:37 minidspshd volumio[688]: SPOTIFY: RECEIVED VOLUMIO VOLUME 77 Jun 21 14:23:38 minidspshd volumio[688]: info: Initializing connection to go-librespot Websocket Jun 21 14:23:38 minidspshd volumio[688]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:23:38 minidspshd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 21 14:23:38 minidspshd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 253. Jun 21 14:23:38 minidspshd systemd[1]: Stopped go-librespot Daemon. Jun 21 14:23:38 minidspshd systemd[1]: Started go-librespot Daemon. Jun 21 14:23:38 minidspshd go-librespot[4322]: go-librespot daemon starting... Jun 21 14:23:38 minidspshd go-librespot[4322]: time="2025-06-21T14:23:38-06:00" level=info msg="running go-librespot 0.2.0" Jun 21 14:23:38 minidspshd go-librespot[4322]: time="2025-06-21T14:23:38-06:00" level=debug msg="app state loaded" Jun 21 14:23:38 minidspshd go-librespot[4322]: time="2025-06-21T14:23:38-06:00" level=debug msg="stored credentials not found" Jun 21 14:23:38 minidspshd go-librespot[4322]: time="2025-06-21T14:23:38-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 21 14:23:38 minidspshd go-librespot[4322]: time="2025-06-21T14:23:38-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 21 14:23:38 minidspshd go-librespot[4322]: time="2025-06-21T14:23:38-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 21 14:23:38 minidspshd go-librespot[4322]: time="2025-06-21T14:23:38-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 21 14:23:38 minidspshd go-librespot[4322]: time="2025-06-21T14:23:38-06:00" level=info msg="zeroconf server listening on port 46255" Jun 21 14:23:38 minidspshd go-librespot[4322]: time="2025-06-21T14:23:38-06:00" level=debug msg="obtained new client token: AACL2p0Ux4gLN+6VsCdxZX2XyvTkpytygiCHSaONv+aSQeWb6C47QuoHzQrxmjdgEBxvm1skvvUt7ps7mgfg+WgOIdWU/E7759/Iv0ZLjahqx2lWoZL7CIcS8pjVgU2zC93gr8eW/CCVMVK8JTrBcaqLolxeFEweD2bP/nd3NNdUG+jrNLDYqnS9eG/UtghiftM0jzYAFWUrz4UpAELy92pWeo+hI5hoNCVK3HZpdZEg+YeoH7m1W1c=" Jun 21 14:23:38 minidspshd go-librespot[4322]: time="2025-06-21T14:23:38-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jun 21 14:23:39 minidspshd go-librespot[4322]: time="2025-06-21T14:23:39-06:00" level=debug msg="completed keyexchange" Jun 21 14:23:39 minidspshd go-librespot[4322]: time="2025-06-21T14:23:39-06:00" level=debug msg="completed challenge" Jun 21 14:23:39 minidspshd go-librespot[4322]: time="2025-06-21T14:23:39-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 21 14:23:39 minidspshd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 21 14:23:39 minidspshd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 21 14:23:41 minidspshd volumio[688]: info: Initializing connection to go-librespot Websocket Jun 21 14:23:41 minidspshd volumio[688]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:23:42 minidspshd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 21 14:23:42 minidspshd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 254. Jun 21 14:23:42 minidspshd systemd[1]: Stopped go-librespot Daemon. Jun 21 14:23:42 minidspshd systemd[1]: Started go-librespot Daemon. Jun 21 14:23:42 minidspshd go-librespot[4331]: go-librespot daemon starting... Jun 21 14:23:42 minidspshd go-librespot[4331]: time="2025-06-21T14:23:42-06:00" level=info msg="running go-librespot 0.2.0" Jun 21 14:23:42 minidspshd go-librespot[4331]: time="2025-06-21T14:23:42-06:00" level=debug msg="app state loaded" Jun 21 14:23:42 minidspshd go-librespot[4331]: time="2025-06-21T14:23:42-06:00" level=debug msg="stored credentials not found" Jun 21 14:23:42 minidspshd go-librespot[4331]: time="2025-06-21T14:23:42-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 21 14:23:42 minidspshd go-librespot[4331]: time="2025-06-21T14:23:42-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 21 14:23:42 minidspshd go-librespot[4331]: time="2025-06-21T14:23:42-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 21 14:23:42 minidspshd go-librespot[4331]: time="2025-06-21T14:23:42-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 21 14:23:42 minidspshd go-librespot[4331]: time="2025-06-21T14:23:42-06:00" level=info msg="zeroconf server listening on port 43693" Jun 21 14:23:42 minidspshd go-librespot[4331]: time="2025-06-21T14:23:42-06:00" level=debug msg="obtained new client token: AAB1wlkAlaBDpYUyt3fvgkl770csiKRbHh0RCI3/dfLy5cFRyXQ5PA5skF9WE9HT/oTb0jUtjvHmWo4QYgfSCb18Lt1PjPWZrzi+dvlGskc/oMJOAe5DupsSbQznreqav0TW2XZvRWZx1E9v6NXU8i543qa4iMiXwEPbNpA23vzxRJXJHbPqnEZFowLy4T2qVNrTJ2kx9LOtK5qRR1c9+YVpt7Fm+SthPmdh34xGniPhp/XHlnz9Jyw=" Jun 21 14:23:43 minidspshd go-librespot[4331]: time="2025-06-21T14:23:43-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jun 21 14:23:43 minidspshd go-librespot[4331]: time="2025-06-21T14:23:43-06:00" level=debug msg="completed keyexchange" Jun 21 14:23:43 minidspshd go-librespot[4331]: time="2025-06-21T14:23:43-06:00" level=debug msg="completed challenge" Jun 21 14:23:43 minidspshd go-librespot[4331]: time="2025-06-21T14:23:43-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 21 14:23:43 minidspshd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 21 14:23:43 minidspshd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 21 14:23:44 minidspshd volumio[688]: info: Initializing connection to go-librespot Websocket Jun 21 14:23:44 minidspshd volumio[688]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 21 14:23:46 minidspshd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 21 14:23:46 minidspshd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 255. Jun 21 14:23:46 minidspshd systemd[1]: Stopped go-librespot Daemon. Jun 21 14:23:46 minidspshd systemd[1]: Started go-librespot Daemon. Jun 21 14:23:46 minidspshd go-librespot[4339]: go-librespot daemon starting... Jun 21 14:23:46 minidspshd go-librespot[4339]: time="2025-06-21T14:23:46-06:00" level=info msg="running go-librespot 0.2.0" Jun 21 14:23:46 minidspshd go-librespot[4339]: time="2025-06-21T14:23:46-06:00" level=debug msg="app state loaded" Jun 21 14:23:46 minidspshd go-librespot[4339]: time="2025-06-21T14:23:46-06:00" level=debug msg="stored credentials not found" Jun 21 14:23:46 minidspshd go-librespot[4339]: time="2025-06-21T14:23:46-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 21 14:23:46 minidspshd go-librespot[4339]: time="2025-06-21T14:23:46-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 21 14:23:46 minidspshd go-librespot[4339]: time="2025-06-21T14:23:46-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 21 14:23:46 minidspshd go-librespot[4339]: time="2025-06-21T14:23:46-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 21 14:23:46 minidspshd go-librespot[4339]: time="2025-06-21T14:23:46-06:00" level=info msg="zeroconf server listening on port 33037" Jun 21 14:23:46 minidspshd go-librespot[4339]: time="2025-06-21T14:23:46-06:00" level=debug msg="obtained new client token: AAAq2XHCB75jiPSZpcS0hCJEj+ZXKLsC3dTdVl/4wxBcy+7RDTE4NSSLN4kPNJVl231NKwnVZ0ZmuARPTYy2S9+VELheqV0ZiChTXHOcH6RxP2iwtpfcq+j5avWkJVdsNGzsrpJISomHfze/JqKsA1LI2uCpmY8r8TXjUWoNE0PfMoSKUkqAx9VF8z0ZzpvKcMHUoA3Z/v5WQbGCANDQso/dz1DfAsHr8G6kthteq4kCi2ulwewXB6g=" Jun 21 14:23:47 minidspshd go-librespot[4339]: time="2025-06-21T14:23:47-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jun 21 14:23:47 minidspshd go-librespot[4339]: time="2025-06-21T14:23:47-06:00" level=debug msg="completed keyexchange" Jun 21 14:23:47 minidspshd go-librespot[4339]: time="2025-06-21T14:23:47-06:00" level=debug msg="completed challenge" Jun 21 14:23:47 minidspshd volumio[688]: info: Initializing connection to go-librespot Websocket Jun 21 14:23:47 minidspshd go-librespot[4339]: time="2025-06-21T14:23:47-06:00" level=debug msg="new websocket client" Jun 21 14:23:47 minidspshd volumio[688]: info: Connection to go-librespot Websocket established Jun 21 14:23:47 minidspshd go-librespot[4339]: time="2025-06-21T14:23:47-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Jun 21 14:23:47 minidspshd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 21 14:23:47 minidspshd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 21 14:23:47 minidspshd volumio[688]: info: Connection to go-librespot Websocket closed Jun 21 14:23:49 minidspshd volumio[688]: info: CoreCommandRouter::executeOnPlugin: multiroom , audioOutputPlay Jun 21 14:23:49 minidspshd volumio[688]: info: Error : CoreCommandRouter::executeOnPlugin: No method [audioOutputPlay] in plugin multiroom Jun 21 14:23:49 minidspshd volumio[688]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 21 14:23:49 minidspshd volumio[688]: TypeError: Cannot read property 'then' of undefined Jun 21 14:23:49 minidspshd volumio[688]: at outputs.audioOutputPlay (/volumio/app/plugins/audio_interface/outputs/index.js:367:9) Jun 21 14:23:49 minidspshd volumio[688]: at CoreCommandRouter.audioOutputPlay (/volumio/app/index.js:2249:30) Jun 21 14:23:49 minidspshd volumio[688]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1411:26) Jun 21 14:23:49 minidspshd volumio[688]: at Socket.emit (events.js:400:28) Jun 21 14:23:49 minidspshd volumio[688]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 Jun 21 14:23:49 minidspshd volumio[688]: at processTicksAndRejections (internal/process/task_queues.js:77:11) Jun 21 14:23:49 minidspshd volumio[688]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 21 14:23:50 minidspshd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 21 14:23:50 minidspshd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 256. Jun 21 14:23:50 minidspshd systemd[1]: Stopped go-librespot Daemon. Jun 21 14:23:50 minidspshd systemd[1]: Started go-librespot Daemon. Jun 21 14:23:50 minidspshd go-librespot[4355]: go-librespot daemon starting... Jun 21 14:23:50 minidspshd go-librespot[4355]: time="2025-06-21T14:23:50-06:00" level=info msg="running go-librespot 0.2.0" Jun 21 14:23:50 minidspshd go-librespot[4355]: time="2025-06-21T14:23:50-06:00" level=debug msg="app state loaded" Jun 21 14:23:50 minidspshd go-librespot[4355]: time="2025-06-21T14:23:50-06:00" level=debug msg="stored credentials not found" Jun 21 14:23:50 minidspshd go-librespot[4355]: time="2025-06-21T14:23:50-06:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 21 14:23:50 minidspshd sudo[4363]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-06-21 14:22 Jun 21 14:23:50 minidspshd sudo[4363]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="17fcb754ddd6bd152b01008c46cc4ba1ca48bf35" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="281cefcd7a302aa7cfba569185cf7aae19b8c376" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="minidspshd" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 22 Mar 2024 03:13:25 PM CET" VOLUMIO_VERSION="3.608" VOLUMIO_HARDWARE="nanopineo3" VOLUMIO_DEVICENAME="Nanopi Neo3" VOLUMIO_VENDOR="miniDSP" VOLUMIO_MODEL="SHD" VOLUMIO_VENDOR_MODEL="miniDSP SHD" VOLUMIO_HASH="18533ba33f8f92d7e7e459bb30f70beb"