-- Logs begin at Fri 2024-03-22 08:13:25 MDT, end at Tue 2025-05-13 10:44:53 MDT. -- May 13 10:43:00 minidsp-shd go-librespot[3644]: time="2025-05-13T10:42:59-06:00" level=debug msg="stored credentials not found" May 13 10:43:00 minidsp-shd go-librespot[3644]: time="2025-05-13T10:43:00-06:00" level=info msg="api server listening on 127.0.0.1:9879" May 13 10:43:00 minidsp-shd go-librespot[3644]: time="2025-05-13T10:43:00-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]" May 13 10:43:00 minidsp-shd go-librespot[3644]: time="2025-05-13T10:43:00-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]" May 13 10:43:00 minidsp-shd go-librespot[3644]: time="2025-05-13T10:43:00-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]" May 13 10:43:00 minidsp-shd go-librespot[3644]: time="2025-05-13T10:43:00-06:00" level=info msg="zeroconf server listening on port 44399" May 13 10:43:00 minidsp-shd volumio[702]: info: CoreCommandRouter::Reload Ui May 13 10:43:00 minidsp-shd volumio[702]: info: Initializing connection to go-librespot Websocket May 13 10:43:00 minidsp-shd go-librespot[3644]: time="2025-05-13T10:43:00-06:00" level=debug msg="new websocket client" May 13 10:43:00 minidsp-shd volumio[702]: info: Connection to go-librespot Websocket established May 13 10:43:00 minidsp-shd go-librespot[3644]: time="2025-05-13T10:43:00-06:00" level=debug msg="obtained new client token: AADLkYpSLQyCUuKmly0HYG22LgTGaavu+vY6/XSynpKv0IhmcNjG0z4zGEiH3zE7a77WhJOyFbAlIKuh0QB/XpSc8PBk9GpkFINFSUzu2iL4uT8+H6wv+B4lpz3tPFVcROs6k4rkqW/61bMb/hXKcs1vbWk/2rL+TI8/VATnMUpAFGWTCGeDW2FjgsNogQrAunR2gG+YPKt0EznRNJDTxKjkCuWfx1K95Er+QOd9BPKqRYZzOytCS2k=" May 13 10:43:00 minidsp-shd go-librespot[3644]: time="2025-05-13T10:43:00-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" May 13 10:43:00 minidsp-shd go-librespot[3644]: time="2025-05-13T10:43:00-06:00" level=debug msg="completed keyexchange" May 13 10:43:00 minidsp-shd go-librespot[3644]: time="2025-05-13T10:43:00-06:00" level=debug msg="completed challenge" May 13 10:43:01 minidsp-shd go-librespot[3644]: time="2025-05-13T10:43:01-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 " May 13 10:43:01 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 13 10:43:01 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 13 10:43:01 minidsp-shd volumio[702]: info: Connection to go-librespot Websocket closed May 13 10:43:01 minidsp-shd sudo[3653]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 13 10:43:01 minidsp-shd sudo[3653]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 10:43:01 minidsp-shd sudo[3653]: pam_unix(sudo:session): session closed for user root May 13 10:43:01 minidsp-shd sudo[3656]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 13 10:43:01 minidsp-shd sudo[3656]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 10:43:01 minidsp-shd sudo[3656]: pam_unix(sudo:session): session closed for user root May 13 10:43:01 minidsp-shd volumio[702]: 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/136.0.0.0 Safari/537.36 Total Clients: 6 May 13 10:43:01 minidsp-shd volumio[702]: info: CoreCommandRouter::getUIConfigOnPlugin May 13 10:43:01 minidsp-shd volumio[702]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam May 13 10:43:01 minidsp-shd volumio[702]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 13 10:43:01 minidsp-shd volumio[702]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom May 13 10:43:01 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioGetState May 13 10:43:01 minidsp-shd volumio[702]: info: CorePlayQueue::getTrack 1 May 13 10:43:01 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioGetVisibleSources May 13 10:43:01 minidsp-shd volumio[702]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 13 10:43:01 minidsp-shd volumio[702]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 13 10:43:01 minidsp-shd volumio[702]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 13 10:43:01 minidsp-shd volumio[702]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 13 10:43:01 minidsp-shd volumio[702]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 13 10:43:01 minidsp-shd volumio[702]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam May 13 10:43:01 minidsp-shd volumio[702]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam May 13 10:43:01 minidsp-shd volumio[702]: info: Received Get System Version May 13 10:43:01 minidsp-shd volumio[702]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 13 10:43:01 minidsp-shd volumio[702]: info: CoreCommandRouter::executeOnPlugin: appearance , getBackgrounds May 13 10:43:03 minidsp-shd volumio[702]: info: Getting Spotify volume May 13 10:43:03 minidsp-shd volumio[702]: (node:702) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 May 13 10:43:03 minidsp-shd volumio[702]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) May 13 10:43:03 minidsp-shd volumio[702]: (node:702) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 46) May 13 10:43:03 minidsp-shd volumio[702]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 May 13 10:43:03 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioGetState May 13 10:43:03 minidsp-shd volumio[702]: info: CorePlayQueue::getTrack 1 May 13 10:43:03 minidsp-shd volumio[702]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 May 13 10:43:03 minidsp-shd volumio[702]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 13 10:43:03 minidsp-shd volumio[702]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 13 10:43:04 minidsp-shd volumio[702]: info: Initializing connection to go-librespot Websocket May 13 10:43:04 minidsp-shd volumio[702]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 13 10:43:04 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 13 10:43:04 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 140. May 13 10:43:04 minidsp-shd systemd[1]: Stopped go-librespot Daemon. May 13 10:43:04 minidsp-shd systemd[1]: Started go-librespot Daemon. May 13 10:43:04 minidsp-shd go-librespot[3661]: go-librespot daemon starting... May 13 10:43:04 minidsp-shd go-librespot[3661]: time="2025-05-13T10:43:04-06:00" level=info msg="running go-librespot 0.2.0" May 13 10:43:04 minidsp-shd go-librespot[3661]: time="2025-05-13T10:43:04-06:00" level=debug msg="app state loaded" May 13 10:43:04 minidsp-shd go-librespot[3661]: time="2025-05-13T10:43:04-06:00" level=debug msg="stored credentials not found" May 13 10:43:04 minidsp-shd go-librespot[3661]: time="2025-05-13T10:43:04-06:00" level=info msg="api server listening on 127.0.0.1:9879" May 13 10:43:04 minidsp-shd go-librespot[3661]: time="2025-05-13T10:43:04-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]" May 13 10:43:04 minidsp-shd go-librespot[3661]: time="2025-05-13T10:43:04-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]" May 13 10:43:04 minidsp-shd go-librespot[3661]: time="2025-05-13T10:43:04-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]" May 13 10:43:04 minidsp-shd go-librespot[3661]: time="2025-05-13T10:43:04-06:00" level=info msg="zeroconf server listening on port 33737" May 13 10:43:04 minidsp-shd go-librespot[3661]: time="2025-05-13T10:43:04-06:00" level=debug msg="obtained new client token: AACYe//T6pRG2k4Qjc65eRpEWPr8O18buWxvYADiZPVyGzn5L5AVspJ+ROjWW58SHU6EwRJT+z77M6DpUUkbCX10XHnt1DnJ7FyYdKKUgI7O1rcrE2jrQsw65Ns+15D4eyhX5DoMqLCWRCvsuzCP4s99cX2WhJbbJiVLF3mGCp4vvqTpJojyBDFdwFmQhQc9dZIl6lW+pgZIkEc6c9U4hL+aP0rcg51KhjEm/4oro+jHfVSMAEMor14=" May 13 10:43:05 minidsp-shd go-librespot[3661]: time="2025-05-13T10:43:05-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" May 13 10:43:05 minidsp-shd go-librespot[3661]: time="2025-05-13T10:43:05-06:00" level=debug msg="connected to ap-guc3.spotify.com:443" May 13 10:43:05 minidsp-shd go-librespot[3661]: time="2025-05-13T10:43:05-06:00" level=debug msg="completed keyexchange" May 13 10:43:05 minidsp-shd go-librespot[3661]: time="2025-05-13T10:43:05-06:00" level=debug msg="completed challenge" May 13 10:43:05 minidsp-shd go-librespot[3661]: time="2025-05-13T10:43:05-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 " May 13 10:43:05 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 13 10:43:05 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 13 10:43:07 minidsp-shd volumio[702]: info: Initializing connection to go-librespot Websocket May 13 10:43:07 minidsp-shd volumio[702]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 13 10:43:08 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 13 10:43:08 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 141. May 13 10:43:08 minidsp-shd systemd[1]: Stopped go-librespot Daemon. May 13 10:43:08 minidsp-shd systemd[1]: Started go-librespot Daemon. May 13 10:43:08 minidsp-shd go-librespot[3669]: go-librespot daemon starting... May 13 10:43:08 minidsp-shd go-librespot[3669]: time="2025-05-13T10:43:08-06:00" level=info msg="running go-librespot 0.2.0" May 13 10:43:08 minidsp-shd go-librespot[3669]: time="2025-05-13T10:43:08-06:00" level=debug msg="app state loaded" May 13 10:43:08 minidsp-shd go-librespot[3669]: time="2025-05-13T10:43:08-06:00" level=debug msg="stored credentials not found" May 13 10:43:08 minidsp-shd go-librespot[3669]: time="2025-05-13T10:43:08-06:00" level=info msg="api server listening on 127.0.0.1:9879" May 13 10:43:08 minidsp-shd go-librespot[3669]: time="2025-05-13T10:43:08-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]" May 13 10:43:08 minidsp-shd go-librespot[3669]: time="2025-05-13T10:43:08-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]" May 13 10:43:08 minidsp-shd go-librespot[3669]: time="2025-05-13T10:43:08-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]" May 13 10:43:08 minidsp-shd go-librespot[3669]: time="2025-05-13T10:43:08-06:00" level=info msg="zeroconf server listening on port 44357" May 13 10:43:09 minidsp-shd go-librespot[3669]: time="2025-05-13T10:43:09-06:00" level=debug msg="obtained new client token: AADfloYyH7utcUxbeOvDMg0Fa+sMl4ohTT1yiJfY+nrWj4/un0fb1yIHtzlycqyqa0UCvco/9+DWaH8OaLuqd/MXnf4tSKETxJcywC8pQOsA9BRu2qGfDHcF+I8Kmwnewa+3lzQpfaR1Dqi6r7Ht9UEsYPMrQ3QCdaIkYbqOOUT8qbRQy8ckIqSusHRRpmW0Lm+2IJwyocWiBZcT5rls4pF2NocVElZYVIJasH4jsb3kg5VquHMd" May 13 10:43:09 minidsp-shd go-librespot[3669]: time="2025-05-13T10:43:09-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" May 13 10:43:09 minidsp-shd go-librespot[3669]: time="2025-05-13T10:43:09-06:00" level=debug msg="completed keyexchange" May 13 10:43:09 minidsp-shd go-librespot[3669]: time="2025-05-13T10:43:09-06:00" level=debug msg="completed challenge" May 13 10:43:09 minidsp-shd go-librespot[3669]: time="2025-05-13T10:43:09-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 " May 13 10:43:09 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 13 10:43:09 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 13 10:43:10 minidsp-shd volumio[702]: info: Initializing connection to go-librespot Websocket May 13 10:43:10 minidsp-shd volumio[702]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 13 10:43:12 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 13 10:43:12 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 142. May 13 10:43:12 minidsp-shd systemd[1]: Stopped go-librespot Daemon. May 13 10:43:12 minidsp-shd systemd[1]: Started go-librespot Daemon. May 13 10:43:12 minidsp-shd go-librespot[3677]: go-librespot daemon starting... May 13 10:43:12 minidsp-shd go-librespot[3677]: time="2025-05-13T10:43:12-06:00" level=info msg="running go-librespot 0.2.0" May 13 10:43:12 minidsp-shd go-librespot[3677]: time="2025-05-13T10:43:12-06:00" level=debug msg="app state loaded" May 13 10:43:12 minidsp-shd go-librespot[3677]: time="2025-05-13T10:43:12-06:00" level=debug msg="stored credentials not found" May 13 10:43:12 minidsp-shd go-librespot[3677]: time="2025-05-13T10:43:12-06:00" level=info msg="api server listening on 127.0.0.1:9879" May 13 10:43:13 minidsp-shd volumio[702]: info: Initializing connection to go-librespot Websocket May 13 10:43:13 minidsp-shd go-librespot[3677]: time="2025-05-13T10:43:13-06:00" level=debug msg="new websocket client" May 13 10:43:13 minidsp-shd volumio[702]: info: Connection to go-librespot Websocket established May 13 10:43:13 minidsp-shd go-librespot[3677]: time="2025-05-13T10:43: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-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" May 13 10:43:13 minidsp-shd go-librespot[3677]: time="2025-05-13T10:43:13-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]" May 13 10:43:13 minidsp-shd go-librespot[3677]: time="2025-05-13T10:43:13-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]" May 13 10:43:13 minidsp-shd go-librespot[3677]: time="2025-05-13T10:43:13-06:00" level=info msg="zeroconf server listening on port 35185" May 13 10:43:13 minidsp-shd go-librespot[3677]: time="2025-05-13T10:43:13-06:00" level=debug msg="obtained new client token: AAAG0B26X3a5gOgsk/Et7mZPZR2ZsNTn0tR5IVvibLLaMGJeDfQk7C2C7KVc3CVmRNz0kkk/n8/zgfJW6BsISeyxzoUyJAohKlrS/B9Hu6S42Y8pM/b6F6iuLjXcR/6g+3yTctIzltdhmpuRqMpuG7SoMOyjHSR5cWSRul7xgSwVaaWAzY9fAKnJoWH/WaBYlTfIQE5tG8Gcbb//Zjddhx9sYnpolx0DfX0VjlqotYYg2URNk0zGthQ=" May 13 10:43:13 minidsp-shd go-librespot[3677]: time="2025-05-13T10:43:13-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" May 13 10:43:13 minidsp-shd go-librespot[3677]: time="2025-05-13T10:43:13-06:00" level=debug msg="completed keyexchange" May 13 10:43:13 minidsp-shd go-librespot[3677]: time="2025-05-13T10:43:13-06:00" level=debug msg="completed challenge" May 13 10:43:13 minidsp-shd go-librespot[3677]: time="2025-05-13T10:43:13-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 " May 13 10:43:13 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 13 10:43:13 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 13 10:43:13 minidsp-shd volumio[702]: info: Connection to go-librespot Websocket closed May 13 10:43:14 minidsp-shd volumio[702]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri May 13 10:43:14 minidsp-shd volumio[702]: info: In handleBrowseUri, curUri=spotify May 13 10:43:14 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioGetQueue May 13 10:43:14 minidsp-shd volumio[702]: info: CoreStateMachine::getQueue May 13 10:43:14 minidsp-shd volumio[702]: info: CorePlayQueue::getQueue May 13 10:43:14 minidsp-shd volumio[702]: info: Listing playlists May 13 10:43:14 minidsp-shd volumio[702]: info: Preload queue cleared May 13 10:43:14 minidsp-shd volumio[702]: info: Preload queue cleared May 13 10:43:14 minidsp-shd volumio[702]: info: Preload queue cleared May 13 10:43:14 minidsp-shd volumio[702]: info: Preload queue cleared May 13 10:43:16 minidsp-shd volumio[702]: info: Getting Spotify volume May 13 10:43:16 minidsp-shd volumio[702]: (node:702) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 May 13 10:43:16 minidsp-shd volumio[702]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) May 13 10:43:16 minidsp-shd volumio[702]: (node:702) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 47) May 13 10:43:16 minidsp-shd volumio[702]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 May 13 10:43:16 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioGetState May 13 10:43:16 minidsp-shd volumio[702]: info: CorePlayQueue::getTrack 1 May 13 10:43:16 minidsp-shd volumio[702]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 May 13 10:43:16 minidsp-shd volumio[702]: info: Initializing connection to go-librespot Websocket May 13 10:43:16 minidsp-shd volumio[702]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 13 10:43:16 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 13 10:43:16 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 143. May 13 10:43:16 minidsp-shd systemd[1]: Stopped go-librespot Daemon. May 13 10:43:16 minidsp-shd systemd[1]: Started go-librespot Daemon. May 13 10:43:16 minidsp-shd go-librespot[3686]: go-librespot daemon starting... May 13 10:43:16 minidsp-shd go-librespot[3686]: time="2025-05-13T10:43:16-06:00" level=info msg="running go-librespot 0.2.0" May 13 10:43:16 minidsp-shd go-librespot[3686]: time="2025-05-13T10:43:16-06:00" level=debug msg="app state loaded" May 13 10:43:16 minidsp-shd go-librespot[3686]: time="2025-05-13T10:43:16-06:00" level=debug msg="stored credentials not found" May 13 10:43:16 minidsp-shd go-librespot[3686]: time="2025-05-13T10:43:16-06:00" level=info msg="api server listening on 127.0.0.1:9879" May 13 10:43:17 minidsp-shd go-librespot[3686]: time="2025-05-13T10:43:17-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]" May 13 10:43:17 minidsp-shd go-librespot[3686]: time="2025-05-13T10:43:17-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]" May 13 10:43:17 minidsp-shd go-librespot[3686]: time="2025-05-13T10:43:17-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]" May 13 10:43:17 minidsp-shd go-librespot[3686]: time="2025-05-13T10:43:17-06:00" level=info msg="zeroconf server listening on port 32793" May 13 10:43:17 minidsp-shd go-librespot[3686]: time="2025-05-13T10:43:17-06:00" level=debug msg="obtained new client token: AAD1atmqH0ddyWZ6cYc3iICnKXF79PMIlLHr8zJ9EA7clyCnXWnVUhDUUZ8LhWCI+6B+IpcAFdAYlBVDgPT4FSOBLvwWNqjhZvkDfh+1Ke/c5l9zqcT8tSfqIXegV7oSXZL/ZXHXPM1cxPCChuCGQ05VKJNNdrHt/mvsfLxRluyzHkk0879gp3QW7+9jgdhV3eyftjTPscPR5Zmnplmj48q7f5fmCzN4WF/0I/wpJnIyzx155MLje/0=" May 13 10:43:17 minidsp-shd go-librespot[3686]: time="2025-05-13T10:43:17-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" May 13 10:43:17 minidsp-shd go-librespot[3686]: time="2025-05-13T10:43:17-06:00" level=debug msg="completed keyexchange" May 13 10:43:17 minidsp-shd go-librespot[3686]: time="2025-05-13T10:43:17-06:00" level=debug msg="completed challenge" May 13 10:43:17 minidsp-shd go-librespot[3686]: time="2025-05-13T10:43:17-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 " May 13 10:43:17 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 13 10:43:17 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 13 10:43:18 minidsp-shd volumio[702]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri May 13 10:43:18 minidsp-shd volumio[702]: info: In handleBrowseUri, curUri=spotify/playlists May 13 10:43:18 minidsp-shd volumio[702]: info: Preload queue cleared May 13 10:43:19 minidsp-shd volumio[702]: info: Initializing connection to go-librespot Websocket May 13 10:43:19 minidsp-shd volumio[702]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 13 10:43:20 minidsp-shd volumio[702]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 13 10:43:20 minidsp-shd volumio[702]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined May 13 10:43:20 minidsp-shd volumio[702]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates May 13 10:43:20 minidsp-shd volumio[702]: info: Received Get System Version May 13 10:43:20 minidsp-shd volumio[702]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 13 10:43:20 minidsp-shd volumio[702]: info: Received Get System Info May 13 10:43:20 minidsp-shd volumio[702]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 13 10:43:20 minidsp-shd volumio[702]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 13 10:43:20 minidsp-shd volumio[702]: info: Discovery: Getting this device information May 13 10:43:20 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioGetState May 13 10:43:20 minidsp-shd volumio[702]: info: CorePlayQueue::getTrack 1 May 13 10:43:20 minidsp-shd volumio[702]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 13 10:43:20 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 13 10:43:20 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 144. May 13 10:43:20 minidsp-shd systemd[1]: Stopped go-librespot Daemon. May 13 10:43:20 minidsp-shd systemd[1]: Started go-librespot Daemon. May 13 10:43:20 minidsp-shd go-librespot[3694]: go-librespot daemon starting... May 13 10:43:20 minidsp-shd go-librespot[3694]: time="2025-05-13T10:43:20-06:00" level=info msg="running go-librespot 0.2.0" May 13 10:43:21 minidsp-shd go-librespot[3694]: time="2025-05-13T10:43:20-06:00" level=debug msg="app state loaded" May 13 10:43:21 minidsp-shd go-librespot[3694]: time="2025-05-13T10:43:21-06:00" level=debug msg="stored credentials not found" May 13 10:43:21 minidsp-shd go-librespot[3694]: time="2025-05-13T10:43:21-06:00" level=info msg="api server listening on 127.0.0.1:9879" May 13 10:43:21 minidsp-shd go-librespot[3694]: time="2025-05-13T10:43:21-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]" May 13 10:43:21 minidsp-shd go-librespot[3694]: time="2025-05-13T10:43:21-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]" May 13 10:43:21 minidsp-shd go-librespot[3694]: time="2025-05-13T10:43:21-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]" May 13 10:43:21 minidsp-shd go-librespot[3694]: time="2025-05-13T10:43:21-06:00" level=info msg="zeroconf server listening on port 43159" May 13 10:43:21 minidsp-shd go-librespot[3694]: time="2025-05-13T10:43:21-06:00" level=debug msg="obtained new client token: AADySZHEarEp0V+Fs3uy8etssJp+MtwUjVVZsTUIAMtMrKo7QYqKSopmzPYgttfYEoPaYzT4lneIH05R56FW6lx9p0yDV8ZlvVBjlmL6n69k5rMf7zg2B/E3XxiYeTUw8gP7igxPzeKo76vcfAPB/Off7ldYQhGpfnsML3vwlqNHknf4Tm4Bsk0PApicGBohWs/NPxN2IaNcohZJ7LPU6Hc8VjPXtKp6Jyitbup2mUcV8SLL5tLaVxM=" May 13 10:43:21 minidsp-shd go-librespot[3694]: time="2025-05-13T10:43:21-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" May 13 10:43:21 minidsp-shd go-librespot[3694]: time="2025-05-13T10:43:21-06:00" level=debug msg="completed keyexchange" May 13 10:43:21 minidsp-shd go-librespot[3694]: time="2025-05-13T10:43:21-06:00" level=debug msg="completed challenge" May 13 10:43:21 minidsp-shd go-librespot[3694]: time="2025-05-13T10:43:21-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 " May 13 10:43:21 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 13 10:43:21 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 13 10:43:22 minidsp-shd volumio[702]: info: Initializing connection to go-librespot Websocket May 13 10:43:22 minidsp-shd volumio[702]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 13 10:43:24 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 13 10:43:24 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 145. May 13 10:43:24 minidsp-shd systemd[1]: Stopped go-librespot Daemon. May 13 10:43:24 minidsp-shd systemd[1]: Started go-librespot Daemon. May 13 10:43:24 minidsp-shd go-librespot[3702]: go-librespot daemon starting... May 13 10:43:24 minidsp-shd go-librespot[3702]: time="2025-05-13T10:43:24-06:00" level=info msg="running go-librespot 0.2.0" May 13 10:43:24 minidsp-shd go-librespot[3702]: time="2025-05-13T10:43:24-06:00" level=debug msg="app state loaded" May 13 10:43:24 minidsp-shd go-librespot[3702]: time="2025-05-13T10:43:24-06:00" level=debug msg="stored credentials not found" May 13 10:43:25 minidsp-shd go-librespot[3702]: time="2025-05-13T10:43:25-06:00" level=info msg="api server listening on 127.0.0.1:9879" May 13 10:43:25 minidsp-shd go-librespot[3702]: time="2025-05-13T10:43:25-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]" May 13 10:43:25 minidsp-shd go-librespot[3702]: time="2025-05-13T10:43:25-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]" May 13 10:43:25 minidsp-shd go-librespot[3702]: time="2025-05-13T10:43:25-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]" May 13 10:43:25 minidsp-shd go-librespot[3702]: time="2025-05-13T10:43:25-06:00" level=info msg="zeroconf server listening on port 32781" May 13 10:43:25 minidsp-shd volumio[702]: info: Initializing connection to go-librespot Websocket May 13 10:43:25 minidsp-shd go-librespot[3702]: time="2025-05-13T10:43:25-06:00" level=debug msg="new websocket client" May 13 10:43:25 minidsp-shd volumio[702]: info: Connection to go-librespot Websocket established May 13 10:43:25 minidsp-shd go-librespot[3702]: time="2025-05-13T10:43:25-06:00" level=debug msg="obtained new client token: AADof5YfClQZzFFpz5Fl5Ia0jwXmaEU28PZDgBkj+6DT9eBFxQnLL/8JGdDJmBOA3w+2zGZo0Zh4+kmISPNHZYQl5KxwPSEjKrc5tjzN8smWYoVtZsNDBw0mhZwYisrUGbPYId22g53PbnpjcRNXxObYKiUoG2/u/mvWKF69KLA1dAD2XGKjE3nn/yVEz4wRjpJ/dCZeK43Wf5dwcDxMjKx9KiTGCiB2bOMb0CcSLrTR7Yy6GvKM2C4=" May 13 10:43:25 minidsp-shd go-librespot[3702]: time="2025-05-13T10:43:25-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" May 13 10:43:26 minidsp-shd go-librespot[3702]: time="2025-05-13T10:43:26-06:00" level=debug msg="completed keyexchange" May 13 10:43:26 minidsp-shd go-librespot[3702]: time="2025-05-13T10:43:26-06:00" level=debug msg="completed challenge" May 13 10:43:26 minidsp-shd go-librespot[3702]: time="2025-05-13T10:43:26-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 " May 13 10:43:26 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 13 10:43:26 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 13 10:43:26 minidsp-shd volumio[702]: info: Connection to go-librespot Websocket closed May 13 10:43:26 minidsp-shd volumio[702]: info: Preload queue cleared May 13 10:43:26 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioReplaceandPlayItems May 13 10:43:26 minidsp-shd volumio[702]: info: CoreStateMachine::ClearQueue May 13 10:43:26 minidsp-shd volumio[702]: info: CoreStateMachine::stop May 13 10:43:26 minidsp-shd volumio[702]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 10:43:26 minidsp-shd volumio[702]: info: CorePlayQueue::clearPlayQueue May 13 10:43:26 minidsp-shd volumio[702]: info: CorePlayQueue::saveQueue May 13 10:43:26 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioPushQueue May 13 10:43:26 minidsp-shd volumio[702]: info: CoreStateMachine::addQueueItems May 13 10:43:26 minidsp-shd volumio[702]: info: CorePlayQueue::addQueueItems May 13 10:43:26 minidsp-shd volumio[702]: info: Preload queue cleared May 13 10:43:26 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:user:spotify:playlist:3NrcAZjKOFv4mul8rZy6xa May 13 10:43:26 minidsp-shd volumio[702]: info: Exploding uri spotify:user:spotify:playlist:3NrcAZjKOFv4mul8rZy6xa in service spop May 13 10:43:26 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:user:spotify:playlist:3NrcAZjKOFv4mul8rZy6xa May 13 10:43:28 minidsp-shd volumio[702]: info: Getting Spotify volume May 13 10:43:28 minidsp-shd volumio[702]: (node:702) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 May 13 10:43:28 minidsp-shd volumio[702]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) May 13 10:43:28 minidsp-shd volumio[702]: (node:702) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 48) May 13 10:43:28 minidsp-shd volumio[702]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 May 13 10:43:28 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioGetState May 13 10:43:28 minidsp-shd volumio[702]: info: CorePlayQueue::getTrack 1 May 13 10:43:28 minidsp-shd volumio[702]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 May 13 10:43:29 minidsp-shd volumio[702]: info: Initializing connection to go-librespot Websocket May 13 10:43:29 minidsp-shd volumio[702]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 13 10:43:29 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 13 10:43:29 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 146. May 13 10:43:29 minidsp-shd systemd[1]: Stopped go-librespot Daemon. May 13 10:43:29 minidsp-shd systemd[1]: Started go-librespot Daemon. May 13 10:43:29 minidsp-shd go-librespot[3711]: go-librespot daemon starting... May 13 10:43:29 minidsp-shd go-librespot[3711]: time="2025-05-13T10:43:29-06:00" level=info msg="running go-librespot 0.2.0" May 13 10:43:29 minidsp-shd go-librespot[3711]: time="2025-05-13T10:43:29-06:00" level=debug msg="app state loaded" May 13 10:43:29 minidsp-shd go-librespot[3711]: time="2025-05-13T10:43:29-06:00" level=debug msg="stored credentials not found" May 13 10:43:29 minidsp-shd go-librespot[3711]: time="2025-05-13T10:43:29-06:00" level=info msg="api server listening on 127.0.0.1:9879" May 13 10:43:29 minidsp-shd go-librespot[3711]: time="2025-05-13T10:43:29-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]" May 13 10:43:29 minidsp-shd go-librespot[3711]: time="2025-05-13T10:43:29-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]" May 13 10:43:29 minidsp-shd go-librespot[3711]: time="2025-05-13T10:43:29-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]" May 13 10:43:29 minidsp-shd go-librespot[3711]: time="2025-05-13T10:43:29-06:00" level=info msg="zeroconf server listening on port 41883" May 13 10:43:30 minidsp-shd go-librespot[3711]: time="2025-05-13T10:43:30-06:00" level=debug msg="obtained new client token: AAATiVZqQSOjrpauqbkUYyoFyKlNu9EfSzHaRRqIkv4tiK97aPZNfiDGSz37aNc9kyTe57ClypzR62tgSzUe0HVa3k//24WZLBOcNmsO196KwLBZ5bxMH99+S92g0LIfve71Hq1ewihD5nWy7R13h8uJBfW9xH4x9krPVoGMat1EAsl3+bU//Fj0d6QgXm6EX3CnRsfk4qqsCxS3RsDV4zxbXOhPZti80htDJAF1lS+ghMVrY87v" May 13 10:43:30 minidsp-shd go-librespot[3711]: time="2025-05-13T10:43:30-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" May 13 10:43:30 minidsp-shd go-librespot[3711]: time="2025-05-13T10:43:30-06:00" level=debug msg="completed keyexchange" May 13 10:43:30 minidsp-shd go-librespot[3711]: time="2025-05-13T10:43:30-06:00" level=debug msg="completed challenge" May 13 10:43:30 minidsp-shd go-librespot[3711]: time="2025-05-13T10:43:30-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 " May 13 10:43:30 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 13 10:43:30 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 13 10:43:32 minidsp-shd volumio[702]: info: Initializing connection to go-librespot Websocket May 13 10:43:32 minidsp-shd volumio[702]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 13 10:43:32 minidsp-shd volumio[702]: info: Preload queue cleared May 13 10:43:32 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioReplaceandPlayItems May 13 10:43:32 minidsp-shd volumio[702]: info: CoreStateMachine::ClearQueue May 13 10:43:32 minidsp-shd volumio[702]: info: CoreStateMachine::stop May 13 10:43:32 minidsp-shd volumio[702]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 10:43:32 minidsp-shd volumio[702]: info: CorePlayQueue::clearPlayQueue May 13 10:43:32 minidsp-shd volumio[702]: info: CorePlayQueue::saveQueue May 13 10:43:32 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioPushQueue May 13 10:43:32 minidsp-shd volumio[702]: info: CoreStateMachine::addQueueItems May 13 10:43:32 minidsp-shd volumio[702]: info: CorePlayQueue::addQueueItems May 13 10:43:32 minidsp-shd volumio[702]: info: Preload queue cleared May 13 10:43:32 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:user:spotify:playlist:3NrcAZjKOFv4mul8rZy6xa May 13 10:43:32 minidsp-shd volumio[702]: info: Exploding uri spotify:user:spotify:playlist:3NrcAZjKOFv4mul8rZy6xa in service spop May 13 10:43:32 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:user:spotify:playlist:3NrcAZjKOFv4mul8rZy6xa May 13 10:43:32 minidsp-shd volumio[702]: info: Preload queue cleared May 13 10:43:32 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioReplaceandPlayItems May 13 10:43:32 minidsp-shd volumio[702]: info: CoreStateMachine::ClearQueue May 13 10:43:32 minidsp-shd volumio[702]: info: CoreStateMachine::stop May 13 10:43:32 minidsp-shd volumio[702]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 10:43:32 minidsp-shd volumio[702]: info: CorePlayQueue::clearPlayQueue May 13 10:43:32 minidsp-shd volumio[702]: info: CorePlayQueue::saveQueue May 13 10:43:32 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioPushQueue May 13 10:43:32 minidsp-shd volumio[702]: info: CoreStateMachine::addQueueItems May 13 10:43:32 minidsp-shd volumio[702]: info: CorePlayQueue::addQueueItems May 13 10:43:32 minidsp-shd volumio[702]: info: Preload queue cleared May 13 10:43:32 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:user:spotify:playlist:3NrcAZjKOFv4mul8rZy6xa May 13 10:43:32 minidsp-shd volumio[702]: info: Exploding uri spotify:user:spotify:playlist:3NrcAZjKOFv4mul8rZy6xa in service spop May 13 10:43:32 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:user:spotify:playlist:3NrcAZjKOFv4mul8rZy6xa May 13 10:43:33 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 13 10:43:33 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 147. May 13 10:43:33 minidsp-shd systemd[1]: Stopped go-librespot Daemon. May 13 10:43:33 minidsp-shd systemd[1]: Started go-librespot Daemon. May 13 10:43:33 minidsp-shd go-librespot[3719]: go-librespot daemon starting... May 13 10:43:33 minidsp-shd go-librespot[3719]: time="2025-05-13T10:43:33-06:00" level=info msg="running go-librespot 0.2.0" May 13 10:43:33 minidsp-shd go-librespot[3719]: time="2025-05-13T10:43:33-06:00" level=debug msg="app state loaded" May 13 10:43:33 minidsp-shd go-librespot[3719]: time="2025-05-13T10:43:33-06:00" level=debug msg="stored credentials not found" May 13 10:43:33 minidsp-shd go-librespot[3719]: time="2025-05-13T10:43:33-06:00" level=info msg="api server listening on 127.0.0.1:9879" May 13 10:43:33 minidsp-shd go-librespot[3719]: time="2025-05-13T10:43:33-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]" May 13 10:43:33 minidsp-shd go-librespot[3719]: time="2025-05-13T10:43:33-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]" May 13 10:43:33 minidsp-shd go-librespot[3719]: time="2025-05-13T10:43:33-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]" May 13 10:43:33 minidsp-shd go-librespot[3719]: time="2025-05-13T10:43:33-06:00" level=info msg="zeroconf server listening on port 41637" May 13 10:43:34 minidsp-shd go-librespot[3719]: time="2025-05-13T10:43:34-06:00" level=debug msg="obtained new client token: AAAIqJhbwi/lyE+ZsGkjGaLRUMWvUvhxsjaHin5qEuOyZS1GNKJN7RGMYikkX2uMIlKYSKZV3qOeQKpUeiJPLN9HQ13rC1JUintYS38Qjw9098PQjZtIY3sr1GsTDUFXXuufHSblehpchtOgJ9Pzyu5vWuK7TMAeqSQruO7c53L2+sHz4pZcWsbRW2/zoaJUYoG1DTF42MkRoh6ThyrN33CdXwJvBtprMDxlilrJmOMelYFefcb0" May 13 10:43:34 minidsp-shd go-librespot[3719]: time="2025-05-13T10:43:34-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" May 13 10:43:34 minidsp-shd go-librespot[3719]: time="2025-05-13T10:43:34-06:00" level=debug msg="completed keyexchange" May 13 10:43:34 minidsp-shd go-librespot[3719]: time="2025-05-13T10:43:34-06:00" level=debug msg="completed challenge" May 13 10:43:34 minidsp-shd go-librespot[3719]: time="2025-05-13T10:43:34-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 " May 13 10:43:34 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 13 10:43:34 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 13 10:43:35 minidsp-shd volumio[702]: info: Initializing connection to go-librespot Websocket May 13 10:43:35 minidsp-shd volumio[702]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 13 10:43:37 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 13 10:43:37 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 148. May 13 10:43:37 minidsp-shd systemd[1]: Stopped go-librespot Daemon. May 13 10:43:37 minidsp-shd systemd[1]: Started go-librespot Daemon. May 13 10:43:37 minidsp-shd go-librespot[3766]: go-librespot daemon starting... May 13 10:43:37 minidsp-shd go-librespot[3766]: time="2025-05-13T10:43:37-06:00" level=info msg="running go-librespot 0.2.0" May 13 10:43:37 minidsp-shd go-librespot[3766]: time="2025-05-13T10:43:37-06:00" level=debug msg="app state loaded" May 13 10:43:37 minidsp-shd go-librespot[3766]: time="2025-05-13T10:43:37-06:00" level=debug msg="stored credentials not found" May 13 10:43:37 minidsp-shd go-librespot[3766]: time="2025-05-13T10:43:37-06:00" level=info msg="api server listening on 127.0.0.1:9879" May 13 10:43:38 minidsp-shd go-librespot[3766]: time="2025-05-13T10:43: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-gew1.spotify.com:80]" May 13 10:43:38 minidsp-shd go-librespot[3766]: time="2025-05-13T10:43:38-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]" May 13 10:43:38 minidsp-shd go-librespot[3766]: time="2025-05-13T10:43:38-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]" May 13 10:43:38 minidsp-shd go-librespot[3766]: time="2025-05-13T10:43:38-06:00" level=info msg="zeroconf server listening on port 45195" May 13 10:43:38 minidsp-shd volumio[702]: info: Initializing connection to go-librespot Websocket May 13 10:43:38 minidsp-shd go-librespot[3766]: time="2025-05-13T10:43:38-06:00" level=debug msg="new websocket client" May 13 10:43:38 minidsp-shd volumio[702]: info: Connection to go-librespot Websocket established May 13 10:43:38 minidsp-shd go-librespot[3766]: time="2025-05-13T10:43:38-06:00" level=debug msg="obtained new client token: AABajPZdUQdZO4ez//viDsSbqnaBbLP0YWdkzTUXsD8sd4FP70DMakRANOPFOScixgmlWZS1fxQ+wX4JQy1fbwwMqsqe2oHkQn+nHgJHCumc3RkxcWhC83NMu23lGbSL9wxV7+fh/hGD7MsDEa6jq5XtMpv4iFYxYUK0Q3hiSLXqwjmu40s8ZU81nugQeIHJY71WfZVA/aSR0OkGGN5vSzaVsu/NtIaXHP5QUXR8uZy9YEVVYBes2vE=" May 13 10:43:38 minidsp-shd go-librespot[3766]: time="2025-05-13T10:43:38-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" May 13 10:43:38 minidsp-shd go-librespot[3766]: time="2025-05-13T10:43:38-06:00" level=debug msg="completed keyexchange" May 13 10:43:38 minidsp-shd go-librespot[3766]: time="2025-05-13T10:43:38-06:00" level=debug msg="completed challenge" May 13 10:43:38 minidsp-shd go-librespot[3766]: time="2025-05-13T10:43:38-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 " May 13 10:43:38 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 13 10:43:38 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 13 10:43:38 minidsp-shd volumio[702]: info: Connection to go-librespot Websocket closed May 13 10:43:40 minidsp-shd volumio[702]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri May 13 10:43:40 minidsp-shd volumio[702]: info: In handleBrowseUri, curUri=spotify May 13 10:43:40 minidsp-shd volumio[702]: info: Preload queue cleared May 13 10:43:40 minidsp-shd volumio[702]: info: Preload queue cleared May 13 10:43:40 minidsp-shd volumio[702]: info: Preload queue cleared May 13 10:43:40 minidsp-shd volumio[702]: info: Preload queue cleared May 13 10:43:41 minidsp-shd volumio[702]: info: Getting Spotify volume May 13 10:43:41 minidsp-shd volumio[702]: (node:702) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 May 13 10:43:41 minidsp-shd volumio[702]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) May 13 10:43:41 minidsp-shd volumio[702]: (node:702) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 49) May 13 10:43:41 minidsp-shd volumio[702]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 May 13 10:43:41 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioGetState May 13 10:43:41 minidsp-shd volumio[702]: info: CorePlayQueue::getTrack 1 May 13 10:43:41 minidsp-shd volumio[702]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 May 13 10:43:41 minidsp-shd volumio[702]: info: Initializing connection to go-librespot Websocket May 13 10:43:41 minidsp-shd volumio[702]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 13 10:43:41 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 13 10:43:41 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 149. May 13 10:43:41 minidsp-shd systemd[1]: Stopped go-librespot Daemon. May 13 10:43:41 minidsp-shd systemd[1]: Started go-librespot Daemon. May 13 10:43:41 minidsp-shd go-librespot[3775]: go-librespot daemon starting... May 13 10:43:42 minidsp-shd go-librespot[3775]: time="2025-05-13T10:43:42-06:00" level=info msg="running go-librespot 0.2.0" May 13 10:43:42 minidsp-shd go-librespot[3775]: time="2025-05-13T10:43:42-06:00" level=debug msg="app state loaded" May 13 10:43:42 minidsp-shd go-librespot[3775]: time="2025-05-13T10:43:42-06:00" level=debug msg="stored credentials not found" May 13 10:43:42 minidsp-shd go-librespot[3775]: time="2025-05-13T10:43:42-06:00" level=info msg="api server listening on 127.0.0.1:9879" May 13 10:43:42 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioPushQueue May 13 10:43:42 minidsp-shd volumio[702]: info: CorePlayQueue::saveQueue May 13 10:43:42 minidsp-shd volumio[702]: info: CoreStateMachine::updateTrackBlock May 13 10:43:42 minidsp-shd volumio[702]: info: CorePlayQueue::getTrackBlock May 13 10:43:42 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioPlay May 13 10:43:42 minidsp-shd volumio[702]: info: CoreStateMachine::play index 0 May 13 10:43:42 minidsp-shd volumio[702]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 10:43:42 minidsp-shd volumio[702]: info: CoreStateMachine::stop May 13 10:43:42 minidsp-shd volumio[702]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 10:43:42 minidsp-shd volumio[702]: info: CoreStateMachine::play index undefined May 13 10:43:42 minidsp-shd volumio[702]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 10:43:42 minidsp-shd volumio[702]: info: CorePlayQueue::getTrack 0 May 13 10:43:42 minidsp-shd volumio[702]: info: CoreStateMachine::startPlaybackTimer May 13 10:43:42 minidsp-shd volumio[702]: info: CorePlayQueue::getTrack 0 May 13 10:43:42 minidsp-shd volumio[702]: info: [1747154622285] ControllerSpotify::clearAddPlayTrack May 13 10:43:42 minidsp-shd volumio[702]: info: Sending Spotify command with payload to local API: /player/play May 13 10:43:42 minidsp-shd go-librespot[3775]: time="2025-05-13T10:43: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" May 13 10:43:42 minidsp-shd go-librespot[3775]: time="2025-05-13T10:43:42-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]" May 13 10:43:42 minidsp-shd go-librespot[3775]: time="2025-05-13T10:43:42-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]" May 13 10:43:42 minidsp-shd go-librespot[3775]: time="2025-05-13T10:43:42-06:00" level=info msg="zeroconf server listening on port 34817" May 13 10:43:43 minidsp-shd go-librespot[3775]: time="2025-05-13T10:43:43-06:00" level=debug msg="obtained new client token: AAD4+NrxVyTIZxVlf+wzcdPf6HoktCbKIuopn+6WSurC1AEbkzUoe3RUHGMO4SvY8KIV8CicMP/4cM1kryOLLaxu1EnLOuiBhTHyB9buhAu4yjDuxXz9JR6U90EcsDcEfhVUcgUf1htsW2XzgRdgO6u++UcP5SWYfZvxsg7188H15aOvQEEFjsZYyKtOQrRojWzG8EU7Uz+hG5Arh0fqZdS3gXz4rJvYYLn1fTN8YNUoINnGuV7Z" May 13 10:43:43 minidsp-shd go-librespot[3775]: time="2025-05-13T10:43:43-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" May 13 10:43:43 minidsp-shd go-librespot[3775]: time="2025-05-13T10:43:43-06:00" level=debug msg="completed keyexchange" May 13 10:43:43 minidsp-shd go-librespot[3775]: time="2025-05-13T10:43:43-06:00" level=debug msg="completed challenge" May 13 10:43:43 minidsp-shd go-librespot[3775]: time="2025-05-13T10:43: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 " May 13 10:43:43 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 13 10:43:43 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 13 10:43:43 minidsp-shd volumio[702]: error: Failed to send command to Spotify local API: /player/play: Error: socket hang up May 13 10:43:43 minidsp-shd volumio[702]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri May 13 10:43:43 minidsp-shd volumio[702]: info: In handleBrowseUri, curUri=spotify/myrecentlyplayedtracks May 13 10:43:43 minidsp-shd volumio[702]: info: Preload queue cleared May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:6BKeXbg7lYEzz7ZQmtBr6P May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:1ER6or6BKV8UZCr7XHPtys May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:2lnbHAKvq36iBLexF3aU3l May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:4MPMTigoBGW2ZP7qlhEkq8 May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:7IZyS1pGkBCCkurV9LUfYR May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:0j6L4dWmSet6rrgJp2Nzgk May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:4trQo4stTuNtxfqNBq3MdY May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:4trQo4stTuNtxfqNBq3MdY May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:04ptRnX17bfLoQ7i4pZAKc May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:3T5UZQX3XODXm2FH9Ely7M May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:0NrE3PjvSPtmIyLHok2UH2 May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:0NrE3PjvSPtmIyLHok2UH2 May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:427d5G2tODOGaPerzx0KOZ May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:7eRe4bp1oiPnkysVEwdfae May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:6MbanPsJS0clqvZCn6Xvnl May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:2drnrigYRSKsWVWbLSCd1t May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:1OEVbb76LgqOEmzxlwthlm May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:4DiEGckFrl0FcIpcrUP4zb May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:4cMTJ5RpqD5wspXanYuppx May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:3OQh098NqWN1ysZSNGmM2a May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:6tk1vfv2cldg10AOzqHcyK May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:6tk1vfv2cldg10AOzqHcyK May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:7hVIz6qBhDXFqSj2cI7OlM May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:7vqFIklqw8RmH58qTal7vf May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:46SP2JcQDbwh1zg8jqLGWG May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:3YoCIqrOWyt7gV4UDKkCoj May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:7nFt2sGfKWO0pRMrx44c1t May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:1A4vMkbkjwATNaMeqKO7wS May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:6dheFtd3qyYGrb5KB05KSW May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:2TWBu8KQdlGA4SoqeFJ73A May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:1Eta9hB2Z7CGMHHVSNul2J May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:58yns8JtLREtKCzqQIEGBz May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:5qDE6BZ7lgEC2NPuqO8pAL May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:50FAOfQS4JpJbGyZSFX8x6 May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:2NqeffZ7KtvH6T5kFW3Qqj May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:5GAh0yww213mHRQGyDHwk7 May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:2iovnj81gIx6q8owB5R5NS May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:7KMsCnKfE2jjrNhV9AdpZS May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:7KMsCnKfE2jjrNhV9AdpZS May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:2O2cdVdyKnGNwZPL4iye56 May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:6PSDknjbOQTQNo7cwBMduU May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:3VZwP7d1U7tuQjb9JZrSRF May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:4kWGZzYANtGVt6Ox6R9tlf May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:2jMSBk8jNymJngmMj9jGxT May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:7e24GhiKpJF41P3gZLz0GZ May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:1cfxSquzIuVUXxG7yfUmwF May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:3R3qPpiWfYbSqwgS7A8Ypy May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:0Snag7BFP5fx7SonfLcSsh May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:7CbgvHE083TAjaRuEfwwgm May 13 10:43:43 minidsp-shd volumio[702]: info: Preloading song: spotify:track:5EQoSCrUMefedwvGUUl6ey May 13 10:43:43 minidsp-shd volumio[702]: info: Exploding uri spotify:track:6BKeXbg7lYEzz7ZQmtBr6P in service spop May 13 10:43:43 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:6BKeXbg7lYEzz7ZQmtBr6P May 13 10:43:43 minidsp-shd volumio[702]: info: Exploding uri spotify:track:1ER6or6BKV8UZCr7XHPtys in service spop May 13 10:43:43 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:1ER6or6BKV8UZCr7XHPtys May 13 10:43:43 minidsp-shd volumio[702]: info: Exploding uri spotify:track:2lnbHAKvq36iBLexF3aU3l in service spop May 13 10:43:43 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:2lnbHAKvq36iBLexF3aU3l May 13 10:43:44 minidsp-shd volumio[702]: info: Exploding uri spotify:track:4MPMTigoBGW2ZP7qlhEkq8 in service spop May 13 10:43:44 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:4MPMTigoBGW2ZP7qlhEkq8 May 13 10:43:44 minidsp-shd volumio[702]: info: Exploding uri spotify:track:7IZyS1pGkBCCkurV9LUfYR in service spop May 13 10:43:44 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:7IZyS1pGkBCCkurV9LUfYR May 13 10:43:44 minidsp-shd volumio[702]: info: Exploding uri spotify:track:0j6L4dWmSet6rrgJp2Nzgk in service spop May 13 10:43:44 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:0j6L4dWmSet6rrgJp2Nzgk May 13 10:43:44 minidsp-shd volumio[702]: info: Exploding uri spotify:track:4trQo4stTuNtxfqNBq3MdY in service spop May 13 10:43:44 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:4trQo4stTuNtxfqNBq3MdY May 13 10:43:44 minidsp-shd volumio[702]: info: Exploding uri spotify:track:4trQo4stTuNtxfqNBq3MdY in service spop May 13 10:43:44 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:4trQo4stTuNtxfqNBq3MdY May 13 10:43:44 minidsp-shd volumio[702]: info: Exploding uri spotify:track:04ptRnX17bfLoQ7i4pZAKc in service spop May 13 10:43:44 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:04ptRnX17bfLoQ7i4pZAKc May 13 10:43:44 minidsp-shd volumio[702]: info: Exploding uri spotify:track:3T5UZQX3XODXm2FH9Ely7M in service spop May 13 10:43:44 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:3T5UZQX3XODXm2FH9Ely7M May 13 10:43:44 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4MPMTigoBGW2ZP7qlhEkq8","service":"spop","name":"You Go To My Head","artist":"Diana Krall","album":"The Very Best Of Diana Krall","type":"song","duration":405,"albumart":"https://i.scdn.co/image/ab67616d0000b27359f6f6221f51315c52b725b5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:44 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6BKeXbg7lYEzz7ZQmtBr6P","service":"spop","name":"Superstar","artist":"Diana Krall","album":"Wallflower","type":"song","duration":257,"albumart":"https://i.scdn.co/image/ab67616d0000b273e92ff8f74f4ee9efb4587795","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:44 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1ER6or6BKV8UZCr7XHPtys","service":"spop","name":"Calling You","artist":"Cæcilie Norby","album":"My Corner Of The Sky","type":"song","duration":324,"albumart":"https://i.scdn.co/image/ab67616d0000b27393f52f681c6ecd6ffae13b6d","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:44 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2lnbHAKvq36iBLexF3aU3l","service":"spop","name":"Vincent","artist":"Laura Fygi","album":"Jazz Love","type":"song","duration":240,"albumart":"https://i.scdn.co/image/ab67616d0000b273b9dc7fbc882dd2f7e20206f2","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:44 minidsp-shd volumio[702]: info: Exploding uri spotify:track:0NrE3PjvSPtmIyLHok2UH2 in service spop May 13 10:43:44 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:0NrE3PjvSPtmIyLHok2UH2 May 13 10:43:44 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7IZyS1pGkBCCkurV9LUfYR","service":"spop","name":"Days of Wine & Roses","artist":"Jacintha","album":"Autumn Leaves (The Songs of Johnny Mercer)","type":"song","duration":326,"albumart":"https://i.scdn.co/image/ab67616d0000b273ec506618d86fce73063da46a","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:44 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0j6L4dWmSet6rrgJp2Nzgk","service":"spop","name":"No More Blues","artist":"Jim Tomlinson","album":"Brazilian Sketches","type":"song","duration":286,"albumart":"https://i.scdn.co/image/ab67616d0000b273a62471d42c27b3ec1efcb912","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:44 minidsp-shd volumio[702]: info: Exploding uri spotify:track:0NrE3PjvSPtmIyLHok2UH2 in service spop May 13 10:43:44 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:0NrE3PjvSPtmIyLHok2UH2 May 13 10:43:44 minidsp-shd volumio[702]: info: Exploding uri spotify:track:427d5G2tODOGaPerzx0KOZ in service spop May 13 10:43:44 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:427d5G2tODOGaPerzx0KOZ May 13 10:43:44 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4trQo4stTuNtxfqNBq3MdY","service":"spop","name":"It May Be You","artist":"Emilie Schiøtt","album":"After the Rain","type":"song","duration":221,"albumart":"https://i.scdn.co/image/ab67616d0000b273b2c78fc8e7a169f852fdf2f7","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:44 minidsp-shd volumio[702]: info: Exploding uri spotify:track:7eRe4bp1oiPnkysVEwdfae in service spop May 13 10:43:44 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:7eRe4bp1oiPnkysVEwdfae May 13 10:43:44 minidsp-shd volumio[702]: info: Exploding uri spotify:track:6MbanPsJS0clqvZCn6Xvnl in service spop May 13 10:43:44 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:6MbanPsJS0clqvZCn6Xvnl May 13 10:43:44 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3T5UZQX3XODXm2FH9Ely7M","service":"spop","name":"Gentle Rain","artist":"Kandace Springs","album":"The Women Who Raised Me","type":"song","duration":235,"albumart":"https://i.scdn.co/image/ab67616d0000b27341a2b372bf6e3dcb2cec9fc6","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:44 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:04ptRnX17bfLoQ7i4pZAKc","service":"spop","name":"Summertime","artist":"Manhattan Jazz Quartett","album":"New York Lounge Jazz (Vocal Classics)","type":"song","duration":204,"albumart":"https://i.scdn.co/image/ab67616d0000b27345639500371df1dedee2dd0a","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:44 minidsp-shd volumio[702]: info: Exploding uri spotify:track:2drnrigYRSKsWVWbLSCd1t in service spop May 13 10:43:44 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:2drnrigYRSKsWVWbLSCd1t May 13 10:43:44 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4trQo4stTuNtxfqNBq3MdY","service":"spop","name":"It May Be You","artist":"Emilie Schiøtt","album":"After the Rain","type":"song","duration":221,"albumart":"https://i.scdn.co/image/ab67616d0000b273b2c78fc8e7a169f852fdf2f7","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:44 minidsp-shd volumio[702]: info: Exploding uri spotify:track:1OEVbb76LgqOEmzxlwthlm in service spop May 13 10:43:44 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:1OEVbb76LgqOEmzxlwthlm May 13 10:43:44 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0NrE3PjvSPtmIyLHok2UH2","service":"spop","name":"It Never Entered My Mind","artist":"Stacey Kent","album":"In Love Again","type":"song","duration":279,"albumart":"https://i.scdn.co/image/ab67616d0000b27309cd7903cc19feec0ca2d797","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:44 minidsp-shd volumio[702]: info: Exploding uri spotify:track:4DiEGckFrl0FcIpcrUP4zb in service spop May 13 10:43:44 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:4DiEGckFrl0FcIpcrUP4zb May 13 10:43:44 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0NrE3PjvSPtmIyLHok2UH2","service":"spop","name":"It Never Entered My Mind","artist":"Stacey Kent","album":"In Love Again","type":"song","duration":279,"albumart":"https://i.scdn.co/image/ab67616d0000b27309cd7903cc19feec0ca2d797","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:44 minidsp-shd volumio[702]: info: Initializing connection to go-librespot Websocket May 13 10:43:44 minidsp-shd volumio[702]: info: Exploding uri spotify:track:4cMTJ5RpqD5wspXanYuppx in service spop May 13 10:43:44 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:4cMTJ5RpqD5wspXanYuppx May 13 10:43:44 minidsp-shd volumio[702]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 13 10:43:44 minidsp-shd volumio[702]: info: Exploding uri spotify:track:3OQh098NqWN1ysZSNGmM2a in service spop May 13 10:43:44 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:3OQh098NqWN1ysZSNGmM2a May 13 10:43:44 minidsp-shd volumio[702]: info: Exploding uri spotify:track:6tk1vfv2cldg10AOzqHcyK in service spop May 13 10:43:44 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:6tk1vfv2cldg10AOzqHcyK May 13 10:43:44 minidsp-shd volumio[702]: info: Exploding uri spotify:track:6tk1vfv2cldg10AOzqHcyK in service spop May 13 10:43:44 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:6tk1vfv2cldg10AOzqHcyK May 13 10:43:44 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6MbanPsJS0clqvZCn6Xvnl","service":"spop","name":"A Case Of You","artist":"Diana Krall","album":"Wallflower (The Complete Sessions)","type":"song","duration":296,"albumart":"https://i.scdn.co/image/ab67616d0000b273d554b63a3fd95a9db9e08030","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:45 minidsp-shd volumio[702]: info: Exploding uri spotify:track:7hVIz6qBhDXFqSj2cI7OlM in service spop May 13 10:43:45 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:7hVIz6qBhDXFqSj2cI7OlM May 13 10:43:45 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2drnrigYRSKsWVWbLSCd1t","service":"spop","name":"Love Letters","artist":"Diana Krall","album":"The Look Of Love","type":"song","duration":295,"albumart":"https://i.scdn.co/image/ab67616d0000b273797b5bf662679f243b717b6f","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:45 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:427d5G2tODOGaPerzx0KOZ","service":"spop","name":"And the Angels Sing","artist":"Jacintha","album":"Autumn Leaves (The Songs of Johnny Mercer)","type":"song","duration":209,"albumart":"https://i.scdn.co/image/ab67616d0000b273ec506618d86fce73063da46a","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:45 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7eRe4bp1oiPnkysVEwdfae","service":"spop","name":"The Gentle Rain","artist":"Jim Tomlinson","album":"Brazilian Sketches","type":"song","duration":263,"albumart":"https://i.scdn.co/image/ab67616d0000b273a62471d42c27b3ec1efcb912","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:45 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1OEVbb76LgqOEmzxlwthlm","service":"spop","name":"Light My Fire","artist":"Jacintha","album":"Jacintha Is Her Name (Dedicated to Julie London)","type":"song","duration":243,"albumart":"https://i.scdn.co/image/ab67616d0000b273fdf34bcc567c0b8281580305","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:45 minidsp-shd volumio[702]: info: Exploding uri spotify:track:7vqFIklqw8RmH58qTal7vf in service spop May 13 10:43:45 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:7vqFIklqw8RmH58qTal7vf May 13 10:43:45 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3OQh098NqWN1ysZSNGmM2a","service":"spop","name":"Polka Dots & Moonbeams","artist":"Stacey Kent","album":"Dreamsville","type":"song","duration":274,"albumart":"https://i.scdn.co/image/ab67616d0000b273af8a1cd853dbc24180a9ca90","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:45 minidsp-shd volumio[702]: info: Exploding uri spotify:track:46SP2JcQDbwh1zg8jqLGWG in service spop May 13 10:43:45 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:46SP2JcQDbwh1zg8jqLGWG May 13 10:43:45 minidsp-shd volumio[702]: info: Exploding uri spotify:track:3YoCIqrOWyt7gV4UDKkCoj in service spop May 13 10:43:45 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:3YoCIqrOWyt7gV4UDKkCoj May 13 10:43:45 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4DiEGckFrl0FcIpcrUP4zb","service":"spop","name":"He Loves And She Loves - Remastered","artist":"Stacey Kent","album":"Let Yourself Go (Remastered)","type":"song","duration":264,"albumart":"https://i.scdn.co/image/ab67616d0000b2737721733442324a2c4fccd460","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:45 minidsp-shd volumio[702]: info: Exploding uri spotify:track:7nFt2sGfKWO0pRMrx44c1t in service spop May 13 10:43:45 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:7nFt2sGfKWO0pRMrx44c1t May 13 10:43:45 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4cMTJ5RpqD5wspXanYuppx","service":"spop","name":"Skylark","artist":"Jacintha","album":"Autumn Leaves (The Songs of Johnny Mercer)","type":"song","duration":317,"albumart":"https://i.scdn.co/image/ab67616d0000b273ec506618d86fce73063da46a","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:45 minidsp-shd volumio[702]: info: Exploding uri spotify:track:1A4vMkbkjwATNaMeqKO7wS in service spop May 13 10:43:45 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:1A4vMkbkjwATNaMeqKO7wS May 13 10:43:45 minidsp-shd volumio[702]: info: Exploding uri spotify:track:6dheFtd3qyYGrb5KB05KSW in service spop May 13 10:43:45 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:6dheFtd3qyYGrb5KB05KSW May 13 10:43:45 minidsp-shd volumio[702]: info: Exploding uri spotify:track:2TWBu8KQdlGA4SoqeFJ73A in service spop May 13 10:43:45 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:2TWBu8KQdlGA4SoqeFJ73A May 13 10:43:45 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6tk1vfv2cldg10AOzqHcyK","service":"spop","name":"There Will Never Be Another You","artist":"Stacey Kent","album":"Tenderly","type":"song","duration":243,"albumart":"https://i.scdn.co/image/ab67616d0000b2733a4128707d7b9c28232158dc","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:45 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7vqFIklqw8RmH58qTal7vf","service":"spop","name":"Corcovado - Quiet Nights of Quiet Stars","artist":"Jim Tomlinson","album":"The Lyric","type":"song","duration":228,"albumart":"https://i.scdn.co/image/ab67616d0000b27352c40aff8c8f233c2ee3db41","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:45 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6tk1vfv2cldg10AOzqHcyK","service":"spop","name":"There Will Never Be Another You","artist":"Stacey Kent","album":"Tenderly","type":"song","duration":243,"albumart":"https://i.scdn.co/image/ab67616d0000b2733a4128707d7b9c28232158dc","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:45 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7hVIz6qBhDXFqSj2cI7OlM","service":"spop","name":"Like A Star","artist":"Laura Fygi","album":"Jazz Love","type":"song","duration":241,"albumart":"https://i.scdn.co/image/ab67616d0000b273b9dc7fbc882dd2f7e20206f2","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:45 minidsp-shd volumio[702]: info: Exploding uri spotify:track:1Eta9hB2Z7CGMHHVSNul2J in service spop May 13 10:43:45 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:1Eta9hB2Z7CGMHHVSNul2J May 13 10:43:45 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:46SP2JcQDbwh1zg8jqLGWG","service":"spop","name":"Here's to Life","artist":"Jacintha","album":"Autumn Leaves (The Songs of Johnny Mercer)","type":"song","duration":287,"albumart":"https://i.scdn.co/image/ab67616d0000b273ec506618d86fce73063da46a","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:45 minidsp-shd volumio[702]: info: Exploding uri spotify:track:58yns8JtLREtKCzqQIEGBz in service spop May 13 10:43:45 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:58yns8JtLREtKCzqQIEGBz May 13 10:43:45 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7nFt2sGfKWO0pRMrx44c1t","service":"spop","name":"Isn't It Romantic","artist":"Diana Krall","album":"Turn Up The Quiet","type":"song","duration":268,"albumart":"https://i.scdn.co/image/ab67616d0000b27307e5cb4306d2162f81abb82d","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:45 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3YoCIqrOWyt7gV4UDKkCoj","service":"spop","name":"Angel Eyes","artist":"Kandace Springs","album":"The Women Who Raised Me","type":"song","duration":360,"albumart":"https://i.scdn.co/image/ab67616d0000b27341a2b372bf6e3dcb2cec9fc6","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:45 minidsp-shd volumio[702]: info: Exploding uri spotify:track:5qDE6BZ7lgEC2NPuqO8pAL in service spop May 13 10:43:45 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:5qDE6BZ7lgEC2NPuqO8pAL May 13 10:43:45 minidsp-shd volumio[702]: info: Exploding uri spotify:track:50FAOfQS4JpJbGyZSFX8x6 in service spop May 13 10:43:45 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:50FAOfQS4JpJbGyZSFX8x6 May 13 10:43:45 minidsp-shd volumio[702]: info: Exploding uri spotify:track:2NqeffZ7KtvH6T5kFW3Qqj in service spop May 13 10:43:45 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:2NqeffZ7KtvH6T5kFW3Qqj May 13 10:43:45 minidsp-shd volumio[702]: info: Exploding uri spotify:track:5GAh0yww213mHRQGyDHwk7 in service spop May 13 10:43:45 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:5GAh0yww213mHRQGyDHwk7 May 13 10:43:45 minidsp-shd volumio[702]: info: Exploding uri spotify:track:2iovnj81gIx6q8owB5R5NS in service spop May 13 10:43:45 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:2iovnj81gIx6q8owB5R5NS May 13 10:43:45 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1A4vMkbkjwATNaMeqKO7wS","service":"spop","name":"I Wish I Were In Love Again","artist":"Stacey Kent","album":"In Love Again","type":"song","duration":246,"albumart":"https://i.scdn.co/image/ab67616d0000b27309cd7903cc19feec0ca2d797","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:45 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6dheFtd3qyYGrb5KB05KSW","service":"spop","name":"And I Love Him","artist":"Laura Fygi","album":"Jazz Love","type":"song","duration":175,"albumart":"https://i.scdn.co/image/ab67616d0000b273b9dc7fbc882dd2f7e20206f2","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:45 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2TWBu8KQdlGA4SoqeFJ73A","service":"spop","name":"Embraceable You","artist":"Stacey Kent","album":"Tenderly","type":"song","duration":222,"albumart":"https://i.scdn.co/image/ab67616d0000b2733a4128707d7b9c28232158dc","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:45 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1Eta9hB2Z7CGMHHVSNul2J","service":"spop","name":"Love Is All We Have","artist":"Kandace Springs","album":"My Name Is Sheba","type":"song","duration":221,"albumart":"https://i.scdn.co/image/ab67616d0000b273e4dd0aaa9be92244d33549d1","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:45 minidsp-shd volumio[702]: info: Exploding uri spotify:track:7KMsCnKfE2jjrNhV9AdpZS in service spop May 13 10:43:45 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:7KMsCnKfE2jjrNhV9AdpZS May 13 10:43:45 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:58yns8JtLREtKCzqQIEGBz","service":"spop","name":"Place To Hide","artist":"Kandace Springs","album":"Soul Eyes","type":"song","duration":224,"albumart":"https://i.scdn.co/image/ab67616d0000b2739376f5d1c51c92f82e07dbc9","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:45 minidsp-shd volumio[702]: info: Exploding uri spotify:track:7KMsCnKfE2jjrNhV9AdpZS in service spop May 13 10:43:45 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:7KMsCnKfE2jjrNhV9AdpZS May 13 10:43:45 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:50FAOfQS4JpJbGyZSFX8x6","service":"spop","name":"The Right to Love","artist":"Cæcilie Norby","album":"My Corner Of The Sky","type":"song","duration":180,"albumart":"https://i.scdn.co/image/ab67616d0000b27393f52f681c6ecd6ffae13b6d","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:45 minidsp-shd volumio[702]: info: Exploding uri spotify:track:2O2cdVdyKnGNwZPL4iye56 in service spop May 13 10:43:45 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:2O2cdVdyKnGNwZPL4iye56 May 13 10:43:45 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5qDE6BZ7lgEC2NPuqO8pAL","service":"spop","name":"Wouldn't You Like to Know","artist":"Heather Rigdon","album":"Everything to Me","type":"song","duration":224,"albumart":"https://i.scdn.co/image/ab67616d0000b27397b7e33b0989e3ae1df0a077","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:45 minidsp-shd volumio[702]: info: Exploding uri spotify:track:6PSDknjbOQTQNo7cwBMduU in service spop May 13 10:43:45 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:6PSDknjbOQTQNo7cwBMduU May 13 10:43:45 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2NqeffZ7KtvH6T5kFW3Qqj","service":"spop","name":"Soul Eyes","artist":"Kandace Springs","album":"Soul Eyes","type":"song","duration":202,"albumart":"https://i.scdn.co/image/ab67616d0000b2739376f5d1c51c92f82e07dbc9","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:45 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5GAh0yww213mHRQGyDHwk7","service":"spop","name":"I Can't Tell You Why","artist":"Diana Krall","album":"Wallflower","type":"song","duration":220,"albumart":"https://i.scdn.co/image/ab67616d0000b273e92ff8f74f4ee9efb4587795","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:45 minidsp-shd volumio[702]: info: Exploding uri spotify:track:3VZwP7d1U7tuQjb9JZrSRF in service spop May 13 10:43:45 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:3VZwP7d1U7tuQjb9JZrSRF May 13 10:43:46 minidsp-shd volumio[702]: info: Exploding uri spotify:track:4kWGZzYANtGVt6Ox6R9tlf in service spop May 13 10:43:46 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:4kWGZzYANtGVt6Ox6R9tlf May 13 10:43:46 minidsp-shd volumio[702]: info: Exploding uri spotify:track:2jMSBk8jNymJngmMj9jGxT in service spop May 13 10:43:46 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:2jMSBk8jNymJngmMj9jGxT May 13 10:43:46 minidsp-shd volumio[702]: info: Exploding uri spotify:track:7e24GhiKpJF41P3gZLz0GZ in service spop May 13 10:43:46 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:7e24GhiKpJF41P3gZLz0GZ May 13 10:43:46 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7KMsCnKfE2jjrNhV9AdpZS","service":"spop","name":"Don't Misunderstand (feat. Norah Jones)","artist":"Harold Mabern","album":"Afro Blue","type":"song","duration":262,"albumart":"https://i.scdn.co/image/ab67616d0000b27323467f06cc173c9b809ab0c0","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:46 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2iovnj81gIx6q8owB5R5NS","service":"spop","name":"Portrait In Black & White","artist":"Jim Tomlinson","album":"Brazilian Sketches","type":"song","duration":217,"albumart":"https://i.scdn.co/image/ab67616d0000b273a62471d42c27b3ec1efcb912","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:46 minidsp-shd volumio[702]: info: Exploding uri spotify:track:1cfxSquzIuVUXxG7yfUmwF in service spop May 13 10:43:46 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:1cfxSquzIuVUXxG7yfUmwF May 13 10:43:46 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6PSDknjbOQTQNo7cwBMduU","service":"spop","name":"Solitude","artist":"Kandace Springs","album":"The Women Who Raised Me","type":"song","duration":299,"albumart":"https://i.scdn.co/image/ab67616d0000b27341a2b372bf6e3dcb2cec9fc6","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:46 minidsp-shd volumio[702]: info: Exploding uri spotify:track:3R3qPpiWfYbSqwgS7A8Ypy in service spop May 13 10:43:46 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:3R3qPpiWfYbSqwgS7A8Ypy May 13 10:43:46 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7KMsCnKfE2jjrNhV9AdpZS","service":"spop","name":"Don't Misunderstand (feat. Norah Jones)","artist":"Harold Mabern","album":"Afro Blue","type":"song","duration":262,"albumart":"https://i.scdn.co/image/ab67616d0000b27323467f06cc173c9b809ab0c0","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:46 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2O2cdVdyKnGNwZPL4iye56","service":"spop","name":"I Get Along Without You Very Well","artist":"Diana Krall","album":"The Look Of Love","type":"song","duration":224,"albumart":"https://i.scdn.co/image/ab67616d0000b273797b5bf662679f243b717b6f","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:46 minidsp-shd volumio[702]: info: Exploding uri spotify:track:0Snag7BFP5fx7SonfLcSsh in service spop May 13 10:43:46 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:0Snag7BFP5fx7SonfLcSsh May 13 10:43:46 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3VZwP7d1U7tuQjb9JZrSRF","service":"spop","name":"'S Wonderful","artist":"Diana Krall","album":"The Look Of Love","type":"song","duration":268,"albumart":"https://i.scdn.co/image/ab67616d0000b273797b5bf662679f243b717b6f","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:46 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4kWGZzYANtGVt6Ox6R9tlf","service":"spop","name":"Happiness Is Just A Thing Called Joe","artist":"Ruth Cameron","album":"Roadhouse","type":"song","duration":317,"albumart":"https://i.scdn.co/image/ab67616d0000b273ed413d7611ffe471e803d58c","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:46 minidsp-shd volumio[702]: info: Exploding uri spotify:track:7CbgvHE083TAjaRuEfwwgm in service spop May 13 10:43:46 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:7CbgvHE083TAjaRuEfwwgm May 13 10:43:46 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2jMSBk8jNymJngmMj9jGxT","service":"spop","name":"House of the Rising Sun","artist":"Somi","album":"House of the Rising Sun","type":"song","duration":225,"albumart":"https://i.scdn.co/image/ab67616d0000b2733983d67ceb75b9c0afd218c9","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:46 minidsp-shd volumio[702]: info: Exploding uri spotify:track:5EQoSCrUMefedwvGUUl6ey in service spop May 13 10:43:46 minidsp-shd volumio[702]: SPOTIFY: EXPLODING URI:spotify:track:5EQoSCrUMefedwvGUUl6ey May 13 10:43:46 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 13 10:43:46 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 150. May 13 10:43:46 minidsp-shd systemd[1]: Stopped go-librespot Daemon. May 13 10:43:46 minidsp-shd systemd[1]: Started go-librespot Daemon. May 13 10:43:46 minidsp-shd go-librespot[3784]: go-librespot daemon starting... May 13 10:43:46 minidsp-shd go-librespot[3784]: time="2025-05-13T10:43:46-06:00" level=info msg="running go-librespot 0.2.0" May 13 10:43:46 minidsp-shd go-librespot[3784]: time="2025-05-13T10:43:46-06:00" level=debug msg="app state loaded" May 13 10:43:46 minidsp-shd go-librespot[3784]: time="2025-05-13T10:43:46-06:00" level=debug msg="stored credentials not found" May 13 10:43:46 minidsp-shd go-librespot[3784]: time="2025-05-13T10:43:46-06:00" level=info msg="api server listening on 127.0.0.1:9879" May 13 10:43:46 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7e24GhiKpJF41P3gZLz0GZ","service":"spop","name":"Most of the Time","artist":"Lisa Ekdahl","album":"Most of the Time","type":"song","duration":229,"albumart":"https://i.scdn.co/image/ab67616d0000b2737798313df73f5c1f4509b8ff","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:46 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1cfxSquzIuVUXxG7yfUmwF","service":"spop","name":"Just Like Heaven","artist":"Kat Edmonson","album":"Take To The Sky","type":"song","duration":252,"albumart":"https://i.scdn.co/image/ab67616d0000b273f87dab2c046b1c32b99aed25","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:46 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3R3qPpiWfYbSqwgS7A8Ypy","service":"spop","name":"Nothing Compares 2 U","artist":"Jimmy Scott","album":"Pedro Almodóvar - Viva La Tristeza!","type":"song","duration":378,"albumart":"https://i.scdn.co/image/ab67616d0000b2736436cac21081118469051f71","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:46 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7CbgvHE083TAjaRuEfwwgm","service":"spop","name":"You've Got A Friend","artist":"Stacey Kent","album":"The Boy Next Door (Special Edition)","type":"song","duration":261,"albumart":"https://i.scdn.co/image/ab67616d0000b27348cf733d555bd7f6e663254d","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:46 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0Snag7BFP5fx7SonfLcSsh","service":"spop","name":"I Got You - I Feel Good","artist":"Joshua Redman","album":"Joshua Redman","type":"song","duration":279,"albumart":"https://i.scdn.co/image/ab67616d0000b27320e855b8f656a2ba69d6fd3d","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:46 minidsp-shd volumio[702]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5EQoSCrUMefedwvGUUl6ey","service":"spop","name":"A Whiter Shade of Pale","artist":"Magnus Lindgren","album":"Stockholm Underground","type":"song","duration":303,"albumart":"https://i.scdn.co/image/ab67616d0000b2733ca225638ce2cc316bf2447f","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 13 10:43:46 minidsp-shd go-librespot[3784]: time="2025-05-13T10:43: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-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" May 13 10:43:46 minidsp-shd go-librespot[3784]: time="2025-05-13T10:43:46-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]" May 13 10:43:46 minidsp-shd go-librespot[3784]: time="2025-05-13T10:43:46-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]" May 13 10:43:46 minidsp-shd go-librespot[3784]: time="2025-05-13T10:43:46-06:00" level=info msg="zeroconf server listening on port 46113" May 13 10:43:47 minidsp-shd go-librespot[3784]: time="2025-05-13T10:43:47-06:00" level=debug msg="obtained new client token: AADpbff4Wk5vINOHe10z2SSAIwH96AXNKNFAgwItK+EC8JDd3gIzGOqKRxhF1PcFFL1OzoMCH1VkRRts2JaGs1ZZLYOPA2kENWQWTDmydNIGk/t/ytnVxs58LZdecpKrllcloabYAlmKf59sLU8g73HNzEIpeeXTPymKOouMVcZjnKYvDpqabRjGh3P2KA1jqw0CGVeCdtK/dcg+3nm6HP/Omt0F554AVrDXcOQBEF6MYWQScQPR" May 13 10:43:47 minidsp-shd go-librespot[3784]: time="2025-05-13T10:43:47-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" May 13 10:43:47 minidsp-shd go-librespot[3784]: time="2025-05-13T10:43:47-06:00" level=debug msg="completed keyexchange" May 13 10:43:47 minidsp-shd go-librespot[3784]: time="2025-05-13T10:43:47-06:00" level=debug msg="completed challenge" May 13 10:43:47 minidsp-shd go-librespot[3784]: time="2025-05-13T10:43: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 " May 13 10:43:47 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 13 10:43:47 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 13 10:43:47 minidsp-shd volumio[702]: info: Initializing connection to go-librespot Websocket May 13 10:43:47 minidsp-shd volumio[702]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 13 10:43:48 minidsp-shd volumio[702]: info: Preload queue cleared May 13 10:43:48 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioReplaceandPlayItems May 13 10:43:48 minidsp-shd volumio[702]: info: CoreStateMachine::ClearQueue May 13 10:43:48 minidsp-shd volumio[702]: info: CoreStateMachine::stop May 13 10:43:48 minidsp-shd volumio[702]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 10:43:48 minidsp-shd volumio[702]: info: CorePlayQueue::clearPlayQueue May 13 10:43:48 minidsp-shd volumio[702]: info: CorePlayQueue::saveQueue May 13 10:43:48 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioPushQueue May 13 10:43:48 minidsp-shd volumio[702]: info: CoreStateMachine::addQueueItems May 13 10:43:48 minidsp-shd volumio[702]: info: CorePlayQueue::addQueueItems May 13 10:43:48 minidsp-shd volumio[702]: info: Preload queue cleared May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:6BKeXbg7lYEzz7ZQmtBr6P May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:6BKeXbg7lYEzz7ZQmtBr6P May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:1ER6or6BKV8UZCr7XHPtys May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:1ER6or6BKV8UZCr7XHPtys May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:2lnbHAKvq36iBLexF3aU3l May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:2lnbHAKvq36iBLexF3aU3l May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:4MPMTigoBGW2ZP7qlhEkq8 May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:4MPMTigoBGW2ZP7qlhEkq8 May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:7IZyS1pGkBCCkurV9LUfYR May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:7IZyS1pGkBCCkurV9LUfYR May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:0j6L4dWmSet6rrgJp2Nzgk May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:0j6L4dWmSet6rrgJp2Nzgk May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:4trQo4stTuNtxfqNBq3MdY May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:4trQo4stTuNtxfqNBq3MdY May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:4trQo4stTuNtxfqNBq3MdY May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:4trQo4stTuNtxfqNBq3MdY May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:04ptRnX17bfLoQ7i4pZAKc May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:04ptRnX17bfLoQ7i4pZAKc May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:3T5UZQX3XODXm2FH9Ely7M May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:3T5UZQX3XODXm2FH9Ely7M May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:0NrE3PjvSPtmIyLHok2UH2 May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:0NrE3PjvSPtmIyLHok2UH2 May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:0NrE3PjvSPtmIyLHok2UH2 May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:0NrE3PjvSPtmIyLHok2UH2 May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:427d5G2tODOGaPerzx0KOZ May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:427d5G2tODOGaPerzx0KOZ May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:7eRe4bp1oiPnkysVEwdfae May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:7eRe4bp1oiPnkysVEwdfae May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:6MbanPsJS0clqvZCn6Xvnl May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:6MbanPsJS0clqvZCn6Xvnl May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:2drnrigYRSKsWVWbLSCd1t May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:2drnrigYRSKsWVWbLSCd1t May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:1OEVbb76LgqOEmzxlwthlm May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:1OEVbb76LgqOEmzxlwthlm May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:4DiEGckFrl0FcIpcrUP4zb May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:4DiEGckFrl0FcIpcrUP4zb May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:4cMTJ5RpqD5wspXanYuppx May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:4cMTJ5RpqD5wspXanYuppx May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:3OQh098NqWN1ysZSNGmM2a May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:3OQh098NqWN1ysZSNGmM2a May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:6tk1vfv2cldg10AOzqHcyK May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:6tk1vfv2cldg10AOzqHcyK May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:6tk1vfv2cldg10AOzqHcyK May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:6tk1vfv2cldg10AOzqHcyK May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:7hVIz6qBhDXFqSj2cI7OlM May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:7hVIz6qBhDXFqSj2cI7OlM May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:7vqFIklqw8RmH58qTal7vf May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:7vqFIklqw8RmH58qTal7vf May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:46SP2JcQDbwh1zg8jqLGWG May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:46SP2JcQDbwh1zg8jqLGWG May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:3YoCIqrOWyt7gV4UDKkCoj May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:3YoCIqrOWyt7gV4UDKkCoj May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:7nFt2sGfKWO0pRMrx44c1t May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:7nFt2sGfKWO0pRMrx44c1t May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:1A4vMkbkjwATNaMeqKO7wS May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:1A4vMkbkjwATNaMeqKO7wS May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:6dheFtd3qyYGrb5KB05KSW May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:6dheFtd3qyYGrb5KB05KSW May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:2TWBu8KQdlGA4SoqeFJ73A May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:2TWBu8KQdlGA4SoqeFJ73A May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:1Eta9hB2Z7CGMHHVSNul2J May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:1Eta9hB2Z7CGMHHVSNul2J May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:58yns8JtLREtKCzqQIEGBz May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:58yns8JtLREtKCzqQIEGBz May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:5qDE6BZ7lgEC2NPuqO8pAL May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:5qDE6BZ7lgEC2NPuqO8pAL May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:50FAOfQS4JpJbGyZSFX8x6 May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:50FAOfQS4JpJbGyZSFX8x6 May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:2NqeffZ7KtvH6T5kFW3Qqj May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:2NqeffZ7KtvH6T5kFW3Qqj May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:5GAh0yww213mHRQGyDHwk7 May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:5GAh0yww213mHRQGyDHwk7 May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:2iovnj81gIx6q8owB5R5NS May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:2iovnj81gIx6q8owB5R5NS May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:7KMsCnKfE2jjrNhV9AdpZS May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:7KMsCnKfE2jjrNhV9AdpZS May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:7KMsCnKfE2jjrNhV9AdpZS May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:7KMsCnKfE2jjrNhV9AdpZS May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:2O2cdVdyKnGNwZPL4iye56 May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:2O2cdVdyKnGNwZPL4iye56 May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:6PSDknjbOQTQNo7cwBMduU May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:6PSDknjbOQTQNo7cwBMduU May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:3VZwP7d1U7tuQjb9JZrSRF May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:3VZwP7d1U7tuQjb9JZrSRF May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:4kWGZzYANtGVt6Ox6R9tlf May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:4kWGZzYANtGVt6Ox6R9tlf May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:2jMSBk8jNymJngmMj9jGxT May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:2jMSBk8jNymJngmMj9jGxT May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:7e24GhiKpJF41P3gZLz0GZ May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:7e24GhiKpJF41P3gZLz0GZ May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:1cfxSquzIuVUXxG7yfUmwF May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:1cfxSquzIuVUXxG7yfUmwF May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:3R3qPpiWfYbSqwgS7A8Ypy May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:3R3qPpiWfYbSqwgS7A8Ypy May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:0Snag7BFP5fx7SonfLcSsh May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:0Snag7BFP5fx7SonfLcSsh May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:7CbgvHE083TAjaRuEfwwgm May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:7CbgvHE083TAjaRuEfwwgm May 13 10:43:48 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:5EQoSCrUMefedwvGUUl6ey May 13 10:43:48 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:5EQoSCrUMefedwvGUUl6ey May 13 10:43:48 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioPushQueue May 13 10:43:48 minidsp-shd volumio[702]: info: CorePlayQueue::saveQueue May 13 10:43:48 minidsp-shd volumio[702]: info: CoreStateMachine::updateTrackBlock May 13 10:43:48 minidsp-shd volumio[702]: info: CorePlayQueue::getTrackBlock May 13 10:43:48 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioPlay May 13 10:43:48 minidsp-shd volumio[702]: info: CoreStateMachine::play index 4 May 13 10:43:48 minidsp-shd volumio[702]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 10:43:48 minidsp-shd volumio[702]: info: CoreStateMachine::stop May 13 10:43:48 minidsp-shd volumio[702]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 10:43:48 minidsp-shd volumio[702]: info: CoreStateMachine::play index undefined May 13 10:43:48 minidsp-shd volumio[702]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 10:43:48 minidsp-shd volumio[702]: info: CorePlayQueue::getTrack 4 May 13 10:43:48 minidsp-shd volumio[702]: info: CoreStateMachine::startPlaybackTimer May 13 10:43:48 minidsp-shd volumio[702]: info: CorePlayQueue::getTrack 4 May 13 10:43:48 minidsp-shd volumio[702]: info: [1747154628263] ControllerSpotify::clearAddPlayTrack May 13 10:43:48 minidsp-shd volumio[702]: info: Sending Spotify command with payload to local API: /player/play May 13 10:43:48 minidsp-shd volumio[702]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 May 13 10:43:48 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioPushQueue May 13 10:43:48 minidsp-shd volumio[702]: info: CorePlayQueue::saveQueue May 13 10:43:48 minidsp-shd volumio[702]: info: CoreStateMachine::updateTrackBlock May 13 10:43:48 minidsp-shd volumio[702]: info: CorePlayQueue::getTrackBlock May 13 10:43:48 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioPlay May 13 10:43:48 minidsp-shd volumio[702]: info: CoreStateMachine::play index 0 May 13 10:43:48 minidsp-shd volumio[702]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 10:43:48 minidsp-shd volumio[702]: info: CoreStateMachine::stop May 13 10:43:48 minidsp-shd volumio[702]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 10:43:48 minidsp-shd volumio[702]: info: CoreStateMachine::play index undefined May 13 10:43:48 minidsp-shd volumio[702]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 10:43:48 minidsp-shd volumio[702]: info: CorePlayQueue::getTrack 0 May 13 10:43:48 minidsp-shd volumio[702]: info: CoreStateMachine::startPlaybackTimer May 13 10:43:48 minidsp-shd volumio[702]: info: CorePlayQueue::getTrack 0 May 13 10:43:48 minidsp-shd volumio[702]: info: [1747154628644] ControllerSpotify::clearAddPlayTrack May 13 10:43:48 minidsp-shd volumio[702]: info: Sending Spotify command with payload to local API: /player/play May 13 10:43:48 minidsp-shd volumio[702]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 May 13 10:43:49 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioPushQueue May 13 10:43:49 minidsp-shd volumio[702]: info: CorePlayQueue::saveQueue May 13 10:43:49 minidsp-shd volumio[702]: info: CoreStateMachine::updateTrackBlock May 13 10:43:49 minidsp-shd volumio[702]: info: CorePlayQueue::getTrackBlock May 13 10:43:49 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioPlay May 13 10:43:49 minidsp-shd volumio[702]: info: CoreStateMachine::play index 50 May 13 10:43:49 minidsp-shd volumio[702]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 10:43:49 minidsp-shd volumio[702]: info: CoreStateMachine::stop May 13 10:43:49 minidsp-shd volumio[702]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 10:43:49 minidsp-shd volumio[702]: info: CoreStateMachine::play index undefined May 13 10:43:49 minidsp-shd volumio[702]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 10:43:49 minidsp-shd volumio[702]: info: CorePlayQueue::getTrack 50 May 13 10:43:49 minidsp-shd volumio[702]: info: CoreStateMachine::startPlaybackTimer May 13 10:43:49 minidsp-shd volumio[702]: info: CorePlayQueue::getTrack 50 May 13 10:43:49 minidsp-shd volumio[702]: info: [1747154629407] ControllerSpotify::clearAddPlayTrack May 13 10:43:49 minidsp-shd volumio[702]: info: Sending Spotify command with payload to local API: /player/play May 13 10:43:49 minidsp-shd volumio[702]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 May 13 10:43:50 minidsp-shd volumio[702]: info: Preload queue cleared May 13 10:43:50 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioReplaceandPlayItems May 13 10:43:50 minidsp-shd volumio[702]: info: CoreStateMachine::ClearQueue May 13 10:43:50 minidsp-shd volumio[702]: info: CoreStateMachine::stop May 13 10:43:50 minidsp-shd volumio[702]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 10:43:50 minidsp-shd volumio[702]: info: CorePlayQueue::clearPlayQueue May 13 10:43:50 minidsp-shd volumio[702]: info: CorePlayQueue::saveQueue May 13 10:43:50 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioPushQueue May 13 10:43:50 minidsp-shd volumio[702]: info: CoreStateMachine::addQueueItems May 13 10:43:50 minidsp-shd volumio[702]: info: CorePlayQueue::addQueueItems May 13 10:43:50 minidsp-shd volumio[702]: info: Preload queue cleared May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:6BKeXbg7lYEzz7ZQmtBr6P May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:6BKeXbg7lYEzz7ZQmtBr6P May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:1ER6or6BKV8UZCr7XHPtys May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:1ER6or6BKV8UZCr7XHPtys May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:2lnbHAKvq36iBLexF3aU3l May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:2lnbHAKvq36iBLexF3aU3l May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:4MPMTigoBGW2ZP7qlhEkq8 May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:4MPMTigoBGW2ZP7qlhEkq8 May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:7IZyS1pGkBCCkurV9LUfYR May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:7IZyS1pGkBCCkurV9LUfYR May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:0j6L4dWmSet6rrgJp2Nzgk May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:0j6L4dWmSet6rrgJp2Nzgk May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:4trQo4stTuNtxfqNBq3MdY May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:4trQo4stTuNtxfqNBq3MdY May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:4trQo4stTuNtxfqNBq3MdY May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:4trQo4stTuNtxfqNBq3MdY May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:04ptRnX17bfLoQ7i4pZAKc May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:04ptRnX17bfLoQ7i4pZAKc May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:3T5UZQX3XODXm2FH9Ely7M May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:3T5UZQX3XODXm2FH9Ely7M May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:0NrE3PjvSPtmIyLHok2UH2 May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:0NrE3PjvSPtmIyLHok2UH2 May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:0NrE3PjvSPtmIyLHok2UH2 May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:0NrE3PjvSPtmIyLHok2UH2 May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:427d5G2tODOGaPerzx0KOZ May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:427d5G2tODOGaPerzx0KOZ May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:7eRe4bp1oiPnkysVEwdfae May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:7eRe4bp1oiPnkysVEwdfae May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:6MbanPsJS0clqvZCn6Xvnl May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:6MbanPsJS0clqvZCn6Xvnl May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:2drnrigYRSKsWVWbLSCd1t May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:2drnrigYRSKsWVWbLSCd1t May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:1OEVbb76LgqOEmzxlwthlm May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:1OEVbb76LgqOEmzxlwthlm May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:4DiEGckFrl0FcIpcrUP4zb May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:4DiEGckFrl0FcIpcrUP4zb May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:4cMTJ5RpqD5wspXanYuppx May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:4cMTJ5RpqD5wspXanYuppx May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:3OQh098NqWN1ysZSNGmM2a May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:3OQh098NqWN1ysZSNGmM2a May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:6tk1vfv2cldg10AOzqHcyK May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:6tk1vfv2cldg10AOzqHcyK May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:6tk1vfv2cldg10AOzqHcyK May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:6tk1vfv2cldg10AOzqHcyK May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:7hVIz6qBhDXFqSj2cI7OlM May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:7hVIz6qBhDXFqSj2cI7OlM May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:7vqFIklqw8RmH58qTal7vf May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:7vqFIklqw8RmH58qTal7vf May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:46SP2JcQDbwh1zg8jqLGWG May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:46SP2JcQDbwh1zg8jqLGWG May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:3YoCIqrOWyt7gV4UDKkCoj May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:3YoCIqrOWyt7gV4UDKkCoj May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:7nFt2sGfKWO0pRMrx44c1t May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:7nFt2sGfKWO0pRMrx44c1t May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:1A4vMkbkjwATNaMeqKO7wS May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:1A4vMkbkjwATNaMeqKO7wS May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:6dheFtd3qyYGrb5KB05KSW May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:6dheFtd3qyYGrb5KB05KSW May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:2TWBu8KQdlGA4SoqeFJ73A May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:2TWBu8KQdlGA4SoqeFJ73A May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:1Eta9hB2Z7CGMHHVSNul2J May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:1Eta9hB2Z7CGMHHVSNul2J May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:58yns8JtLREtKCzqQIEGBz May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:58yns8JtLREtKCzqQIEGBz May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:5qDE6BZ7lgEC2NPuqO8pAL May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:5qDE6BZ7lgEC2NPuqO8pAL May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:50FAOfQS4JpJbGyZSFX8x6 May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:50FAOfQS4JpJbGyZSFX8x6 May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:2NqeffZ7KtvH6T5kFW3Qqj May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:2NqeffZ7KtvH6T5kFW3Qqj May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:5GAh0yww213mHRQGyDHwk7 May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:5GAh0yww213mHRQGyDHwk7 May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:2iovnj81gIx6q8owB5R5NS May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:2iovnj81gIx6q8owB5R5NS May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:7KMsCnKfE2jjrNhV9AdpZS May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:7KMsCnKfE2jjrNhV9AdpZS May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:7KMsCnKfE2jjrNhV9AdpZS May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:7KMsCnKfE2jjrNhV9AdpZS May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:2O2cdVdyKnGNwZPL4iye56 May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:2O2cdVdyKnGNwZPL4iye56 May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:6PSDknjbOQTQNo7cwBMduU May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:6PSDknjbOQTQNo7cwBMduU May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:3VZwP7d1U7tuQjb9JZrSRF May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:3VZwP7d1U7tuQjb9JZrSRF May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:4kWGZzYANtGVt6Ox6R9tlf May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:4kWGZzYANtGVt6Ox6R9tlf May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:2jMSBk8jNymJngmMj9jGxT May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:2jMSBk8jNymJngmMj9jGxT May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:7e24GhiKpJF41P3gZLz0GZ May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:7e24GhiKpJF41P3gZLz0GZ May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:1cfxSquzIuVUXxG7yfUmwF May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:1cfxSquzIuVUXxG7yfUmwF May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:3R3qPpiWfYbSqwgS7A8Ypy May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:3R3qPpiWfYbSqwgS7A8Ypy May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:0Snag7BFP5fx7SonfLcSsh May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:0Snag7BFP5fx7SonfLcSsh May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:7CbgvHE083TAjaRuEfwwgm May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:7CbgvHE083TAjaRuEfwwgm May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:5EQoSCrUMefedwvGUUl6ey May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:5EQoSCrUMefedwvGUUl6ey May 13 10:43:50 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioPushQueue May 13 10:43:50 minidsp-shd volumio[702]: info: CorePlayQueue::saveQueue May 13 10:43:50 minidsp-shd volumio[702]: info: CoreStateMachine::updateTrackBlock May 13 10:43:50 minidsp-shd volumio[702]: info: CorePlayQueue::getTrackBlock May 13 10:43:50 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioPlay May 13 10:43:50 minidsp-shd volumio[702]: info: CoreStateMachine::play index 4 May 13 10:43:50 minidsp-shd volumio[702]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 10:43:50 minidsp-shd volumio[702]: info: CoreStateMachine::stop May 13 10:43:50 minidsp-shd volumio[702]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 10:43:50 minidsp-shd volumio[702]: info: CoreStateMachine::play index undefined May 13 10:43:50 minidsp-shd volumio[702]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 10:43:50 minidsp-shd volumio[702]: info: CorePlayQueue::getTrack 4 May 13 10:43:50 minidsp-shd volumio[702]: info: CoreStateMachine::startPlaybackTimer May 13 10:43:50 minidsp-shd volumio[702]: info: CorePlayQueue::getTrack 4 May 13 10:43:50 minidsp-shd volumio[702]: info: [1747154630269] ControllerSpotify::clearAddPlayTrack May 13 10:43:50 minidsp-shd volumio[702]: info: Sending Spotify command with payload to local API: /player/play May 13 10:43:50 minidsp-shd volumio[702]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 May 13 10:43:50 minidsp-shd volumio[702]: info: Preload queue cleared May 13 10:43:50 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioReplaceandPlayItems May 13 10:43:50 minidsp-shd volumio[702]: info: CoreStateMachine::ClearQueue May 13 10:43:50 minidsp-shd volumio[702]: info: CoreStateMachine::stop May 13 10:43:50 minidsp-shd volumio[702]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 10:43:50 minidsp-shd volumio[702]: info: CorePlayQueue::clearPlayQueue May 13 10:43:50 minidsp-shd volumio[702]: info: CorePlayQueue::saveQueue May 13 10:43:50 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioPushQueue May 13 10:43:50 minidsp-shd volumio[702]: info: CoreStateMachine::addQueueItems May 13 10:43:50 minidsp-shd volumio[702]: info: CorePlayQueue::addQueueItems May 13 10:43:50 minidsp-shd volumio[702]: info: Preload queue cleared May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:6BKeXbg7lYEzz7ZQmtBr6P May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:6BKeXbg7lYEzz7ZQmtBr6P May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:1ER6or6BKV8UZCr7XHPtys May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:1ER6or6BKV8UZCr7XHPtys May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:2lnbHAKvq36iBLexF3aU3l May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:2lnbHAKvq36iBLexF3aU3l May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:4MPMTigoBGW2ZP7qlhEkq8 May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:4MPMTigoBGW2ZP7qlhEkq8 May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:7IZyS1pGkBCCkurV9LUfYR May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:7IZyS1pGkBCCkurV9LUfYR May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:0j6L4dWmSet6rrgJp2Nzgk May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:0j6L4dWmSet6rrgJp2Nzgk May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:4trQo4stTuNtxfqNBq3MdY May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:4trQo4stTuNtxfqNBq3MdY May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:4trQo4stTuNtxfqNBq3MdY May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:4trQo4stTuNtxfqNBq3MdY May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:04ptRnX17bfLoQ7i4pZAKc May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:04ptRnX17bfLoQ7i4pZAKc May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:3T5UZQX3XODXm2FH9Ely7M May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:3T5UZQX3XODXm2FH9Ely7M May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:0NrE3PjvSPtmIyLHok2UH2 May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:0NrE3PjvSPtmIyLHok2UH2 May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:0NrE3PjvSPtmIyLHok2UH2 May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:0NrE3PjvSPtmIyLHok2UH2 May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:427d5G2tODOGaPerzx0KOZ May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:427d5G2tODOGaPerzx0KOZ May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:7eRe4bp1oiPnkysVEwdfae May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:7eRe4bp1oiPnkysVEwdfae May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:6MbanPsJS0clqvZCn6Xvnl May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:6MbanPsJS0clqvZCn6Xvnl May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:2drnrigYRSKsWVWbLSCd1t May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:2drnrigYRSKsWVWbLSCd1t May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:1OEVbb76LgqOEmzxlwthlm May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:1OEVbb76LgqOEmzxlwthlm May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:4DiEGckFrl0FcIpcrUP4zb May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:4DiEGckFrl0FcIpcrUP4zb May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:4cMTJ5RpqD5wspXanYuppx May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:4cMTJ5RpqD5wspXanYuppx May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:3OQh098NqWN1ysZSNGmM2a May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:3OQh098NqWN1ysZSNGmM2a May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:6tk1vfv2cldg10AOzqHcyK May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:6tk1vfv2cldg10AOzqHcyK May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:6tk1vfv2cldg10AOzqHcyK May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:6tk1vfv2cldg10AOzqHcyK May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:7hVIz6qBhDXFqSj2cI7OlM May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:7hVIz6qBhDXFqSj2cI7OlM May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:7vqFIklqw8RmH58qTal7vf May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:7vqFIklqw8RmH58qTal7vf May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:46SP2JcQDbwh1zg8jqLGWG May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:46SP2JcQDbwh1zg8jqLGWG May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:3YoCIqrOWyt7gV4UDKkCoj May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:3YoCIqrOWyt7gV4UDKkCoj May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:7nFt2sGfKWO0pRMrx44c1t May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:7nFt2sGfKWO0pRMrx44c1t May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:1A4vMkbkjwATNaMeqKO7wS May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:1A4vMkbkjwATNaMeqKO7wS May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:6dheFtd3qyYGrb5KB05KSW May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:6dheFtd3qyYGrb5KB05KSW May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:2TWBu8KQdlGA4SoqeFJ73A May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:2TWBu8KQdlGA4SoqeFJ73A May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:1Eta9hB2Z7CGMHHVSNul2J May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:1Eta9hB2Z7CGMHHVSNul2J May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:58yns8JtLREtKCzqQIEGBz May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:58yns8JtLREtKCzqQIEGBz May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:5qDE6BZ7lgEC2NPuqO8pAL May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:5qDE6BZ7lgEC2NPuqO8pAL May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:50FAOfQS4JpJbGyZSFX8x6 May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:50FAOfQS4JpJbGyZSFX8x6 May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:2NqeffZ7KtvH6T5kFW3Qqj May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:2NqeffZ7KtvH6T5kFW3Qqj May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:5GAh0yww213mHRQGyDHwk7 May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:5GAh0yww213mHRQGyDHwk7 May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:2iovnj81gIx6q8owB5R5NS May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:2iovnj81gIx6q8owB5R5NS May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:7KMsCnKfE2jjrNhV9AdpZS May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:7KMsCnKfE2jjrNhV9AdpZS May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:7KMsCnKfE2jjrNhV9AdpZS May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:7KMsCnKfE2jjrNhV9AdpZS May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:2O2cdVdyKnGNwZPL4iye56 May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:2O2cdVdyKnGNwZPL4iye56 May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:6PSDknjbOQTQNo7cwBMduU May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:6PSDknjbOQTQNo7cwBMduU May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:3VZwP7d1U7tuQjb9JZrSRF May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:3VZwP7d1U7tuQjb9JZrSRF May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:4kWGZzYANtGVt6Ox6R9tlf May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:4kWGZzYANtGVt6Ox6R9tlf May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:2jMSBk8jNymJngmMj9jGxT May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:2jMSBk8jNymJngmMj9jGxT May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:7e24GhiKpJF41P3gZLz0GZ May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:7e24GhiKpJF41P3gZLz0GZ May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:1cfxSquzIuVUXxG7yfUmwF May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:1cfxSquzIuVUXxG7yfUmwF May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:3R3qPpiWfYbSqwgS7A8Ypy May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:3R3qPpiWfYbSqwgS7A8Ypy May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:0Snag7BFP5fx7SonfLcSsh May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:0Snag7BFP5fx7SonfLcSsh May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:7CbgvHE083TAjaRuEfwwgm May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:7CbgvHE083TAjaRuEfwwgm May 13 10:43:50 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:5EQoSCrUMefedwvGUUl6ey May 13 10:43:50 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:5EQoSCrUMefedwvGUUl6ey May 13 10:43:50 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioPushQueue May 13 10:43:50 minidsp-shd volumio[702]: info: CorePlayQueue::saveQueue May 13 10:43:50 minidsp-shd volumio[702]: info: CoreStateMachine::updateTrackBlock May 13 10:43:50 minidsp-shd volumio[702]: info: CorePlayQueue::getTrackBlock May 13 10:43:50 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioPlay May 13 10:43:50 minidsp-shd volumio[702]: info: CoreStateMachine::play index 4 May 13 10:43:50 minidsp-shd volumio[702]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 10:43:50 minidsp-shd volumio[702]: info: CoreStateMachine::stop May 13 10:43:50 minidsp-shd volumio[702]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 10:43:50 minidsp-shd volumio[702]: info: CoreStateMachine::play index undefined May 13 10:43:50 minidsp-shd volumio[702]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 10:43:50 minidsp-shd volumio[702]: info: CorePlayQueue::getTrack 4 May 13 10:43:50 minidsp-shd volumio[702]: info: CoreStateMachine::startPlaybackTimer May 13 10:43:50 minidsp-shd volumio[702]: info: CorePlayQueue::getTrack 4 May 13 10:43:50 minidsp-shd volumio[702]: info: [1747154630515] ControllerSpotify::clearAddPlayTrack May 13 10:43:50 minidsp-shd volumio[702]: info: Sending Spotify command with payload to local API: /player/play May 13 10:43:50 minidsp-shd volumio[702]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 May 13 10:43:50 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 13 10:43:50 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 151. May 13 10:43:50 minidsp-shd systemd[1]: Stopped go-librespot Daemon. May 13 10:43:50 minidsp-shd systemd[1]: Started go-librespot Daemon. May 13 10:43:50 minidsp-shd go-librespot[3792]: go-librespot daemon starting... May 13 10:43:50 minidsp-shd go-librespot[3792]: time="2025-05-13T10:43:50-06:00" level=info msg="running go-librespot 0.2.0" May 13 10:43:50 minidsp-shd go-librespot[3792]: time="2025-05-13T10:43:50-06:00" level=debug msg="app state loaded" May 13 10:43:50 minidsp-shd go-librespot[3792]: time="2025-05-13T10:43:50-06:00" level=debug msg="stored credentials not found" May 13 10:43:50 minidsp-shd go-librespot[3792]: time="2025-05-13T10:43:50-06:00" level=info msg="api server listening on 127.0.0.1:9879" May 13 10:43:50 minidsp-shd volumio[702]: info: Initializing connection to go-librespot Websocket May 13 10:43:51 minidsp-shd go-librespot[3792]: time="2025-05-13T10:43:51-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]" May 13 10:43:51 minidsp-shd go-librespot[3792]: time="2025-05-13T10:43:51-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]" May 13 10:43:51 minidsp-shd go-librespot[3792]: time="2025-05-13T10:43:51-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]" May 13 10:43:51 minidsp-shd go-librespot[3792]: time="2025-05-13T10:43:51-06:00" level=info msg="zeroconf server listening on port 42589" May 13 10:43:51 minidsp-shd go-librespot[3792]: time="2025-05-13T10:43:51-06:00" level=debug msg="new websocket client" May 13 10:43:51 minidsp-shd volumio[702]: info: Connection to go-librespot Websocket established May 13 10:43:51 minidsp-shd go-librespot[3792]: time="2025-05-13T10:43:51-06:00" level=debug msg="obtained new client token: AABnQFywcWgv/Wks9iOuA/qx2qyenX6E6eQ0GJeZMAY+rzXOXM0sPfRh7GRcIXrqCrh+n8ReHAqqwU7KJ1VoSlmIfteFNdBAy2XhEQVo3NMm1a7j6vKQc/UwHbayy6s79utArhKK8+ccgDkH7LMGikegfmKho90SO0b4xnu0eNuyjqblaOPo3spoaPeY8+7Z+7Fvv41IIacr+vOn1IsbGB/QdslsGao402o/R14s27ru1NiuZ5NmFI8=" May 13 10:43:51 minidsp-shd go-librespot[3792]: time="2025-05-13T10:43:51-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" May 13 10:43:51 minidsp-shd go-librespot[3792]: time="2025-05-13T10:43:51-06:00" level=debug msg="completed keyexchange" May 13 10:43:51 minidsp-shd go-librespot[3792]: time="2025-05-13T10:43:51-06:00" level=debug msg="completed challenge" May 13 10:43:51 minidsp-shd go-librespot[3792]: time="2025-05-13T10:43:51-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 " May 13 10:43:51 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 13 10:43:51 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 13 10:43:51 minidsp-shd volumio[702]: info: Connection to go-librespot Websocket closed May 13 10:43:54 minidsp-shd volumio[702]: info: Getting Spotify volume May 13 10:43:54 minidsp-shd volumio[702]: (node:702) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 May 13 10:43:54 minidsp-shd volumio[702]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) May 13 10:43:54 minidsp-shd volumio[702]: (node:702) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 50) May 13 10:43:54 minidsp-shd volumio[702]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 May 13 10:43:54 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioGetState May 13 10:43:54 minidsp-shd volumio[702]: info: CorePlayQueue::getTrack 4 May 13 10:43:54 minidsp-shd volumio[702]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 May 13 10:43:54 minidsp-shd volumio[702]: info: Initializing connection to go-librespot Websocket May 13 10:43:54 minidsp-shd volumio[702]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 13 10:43:54 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 13 10:43:54 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 152. May 13 10:43:54 minidsp-shd systemd[1]: Stopped go-librespot Daemon. May 13 10:43:54 minidsp-shd systemd[1]: Started go-librespot Daemon. May 13 10:43:54 minidsp-shd go-librespot[3801]: go-librespot daemon starting... May 13 10:43:54 minidsp-shd go-librespot[3801]: time="2025-05-13T10:43:54-06:00" level=info msg="running go-librespot 0.2.0" May 13 10:43:54 minidsp-shd go-librespot[3801]: time="2025-05-13T10:43:54-06:00" level=debug msg="app state loaded" May 13 10:43:54 minidsp-shd go-librespot[3801]: time="2025-05-13T10:43:54-06:00" level=debug msg="stored credentials not found" May 13 10:43:55 minidsp-shd go-librespot[3801]: time="2025-05-13T10:43:55-06:00" level=info msg="api server listening on 127.0.0.1:9879" May 13 10:43:55 minidsp-shd go-librespot[3801]: time="2025-05-13T10:43:55-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]" May 13 10:43:55 minidsp-shd go-librespot[3801]: time="2025-05-13T10:43:55-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]" May 13 10:43:55 minidsp-shd go-librespot[3801]: time="2025-05-13T10:43:55-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]" May 13 10:43:55 minidsp-shd go-librespot[3801]: time="2025-05-13T10:43:55-06:00" level=info msg="zeroconf server listening on port 45863" May 13 10:43:55 minidsp-shd go-librespot[3801]: time="2025-05-13T10:43:55-06:00" level=debug msg="obtained new client token: AADTQHFiBFyC4SxHacWkIjfoAFyFEU1EtOxf/1YPap+AFVyHYhTLUwjmUvLy8pSyxzLAtVlpHiGoNG8xfS+I3e4YoJv3vIEIwtKk29Sfwy0D4rAPtFOGR+AlmvUcmoMDd/AAG92npD/6+6JepS6VA0VWqpSJC+yD5uSR7caVJ54iNI/2Mv0d3JN/ir95pSDCMVBBVtpCOdhKP6ynHkQrc/YbeyLI5wvYZcaLfzsY3nDiqJudxoNRmvo=" May 13 10:43:55 minidsp-shd go-librespot[3801]: time="2025-05-13T10:43:55-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" May 13 10:43:55 minidsp-shd go-librespot[3801]: time="2025-05-13T10:43:55-06:00" level=debug msg="completed keyexchange" May 13 10:43:55 minidsp-shd go-librespot[3801]: time="2025-05-13T10:43:55-06:00" level=debug msg="completed challenge" May 13 10:43:55 minidsp-shd go-librespot[3801]: time="2025-05-13T10:43:55-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 " May 13 10:43:55 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 13 10:43:55 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 13 10:43:57 minidsp-shd volumio[702]: info: Initializing connection to go-librespot Websocket May 13 10:43:57 minidsp-shd volumio[702]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 13 10:43:59 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 13 10:43:59 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 153. May 13 10:43:59 minidsp-shd systemd[1]: Stopped go-librespot Daemon. May 13 10:43:59 minidsp-shd systemd[1]: Started go-librespot Daemon. May 13 10:43:59 minidsp-shd go-librespot[3809]: go-librespot daemon starting... May 13 10:43:59 minidsp-shd go-librespot[3809]: time="2025-05-13T10:43:59-06:00" level=info msg="running go-librespot 0.2.0" May 13 10:43:59 minidsp-shd go-librespot[3809]: time="2025-05-13T10:43:59-06:00" level=debug msg="app state loaded" May 13 10:43:59 minidsp-shd go-librespot[3809]: time="2025-05-13T10:43:59-06:00" level=debug msg="stored credentials not found" May 13 10:43:59 minidsp-shd go-librespot[3809]: time="2025-05-13T10:43:59-06:00" level=info msg="api server listening on 127.0.0.1:9879" May 13 10:43:59 minidsp-shd go-librespot[3809]: time="2025-05-13T10:43:59-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]" May 13 10:43:59 minidsp-shd go-librespot[3809]: time="2025-05-13T10:43:59-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]" May 13 10:43:59 minidsp-shd go-librespot[3809]: time="2025-05-13T10:43:59-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]" May 13 10:43:59 minidsp-shd go-librespot[3809]: time="2025-05-13T10:43:59-06:00" level=info msg="zeroconf server listening on port 45083" May 13 10:44:00 minidsp-shd go-librespot[3809]: time="2025-05-13T10:44:00-06:00" level=debug msg="obtained new client token: AAC7xWKZa3SDf4n07ZFYJ5k+c2q7q7tyDUYjqIMyNr3g+xkTC+oJzQCzfTGceAFbJYHii/0GTIbtq78X6A9XuzJ1JPMF1TyXcQwyN9jXKXEeRsr9YINOckCFxNZeVzXN1c2G8izKQ/OGQElFmJcplzCqApWm8LKremqHTGIYwDuiEu9tsTBX7+Ch9Ewn4xT9TgAORucEjY1Bd/IN/CIGffSK7lZzQZ8XQbXwQFWJkcMtITQ0W9q63L4=" May 13 10:44:00 minidsp-shd go-librespot[3809]: time="2025-05-13T10:44:00-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" May 13 10:44:00 minidsp-shd go-librespot[3809]: time="2025-05-13T10:44:00-06:00" level=debug msg="completed keyexchange" May 13 10:44:00 minidsp-shd go-librespot[3809]: time="2025-05-13T10:44:00-06:00" level=debug msg="completed challenge" May 13 10:44:00 minidsp-shd go-librespot[3809]: time="2025-05-13T10:44:00-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 " May 13 10:44:00 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 13 10:44:00 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 13 10:44:00 minidsp-shd volumio[702]: info: Initializing connection to go-librespot Websocket May 13 10:44:00 minidsp-shd volumio[702]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 13 10:44:02 minidsp-shd volumio[702]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri May 13 10:44:02 minidsp-shd volumio[702]: info: In handleBrowseUri, curUri=spotify/myalbums May 13 10:44:03 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 13 10:44:03 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 154. May 13 10:44:03 minidsp-shd systemd[1]: Stopped go-librespot Daemon. May 13 10:44:03 minidsp-shd systemd[1]: Started go-librespot Daemon. May 13 10:44:03 minidsp-shd go-librespot[3817]: go-librespot daemon starting... May 13 10:44:03 minidsp-shd go-librespot[3817]: time="2025-05-13T10:44:03-06:00" level=info msg="running go-librespot 0.2.0" May 13 10:44:03 minidsp-shd go-librespot[3817]: time="2025-05-13T10:44:03-06:00" level=debug msg="app state loaded" May 13 10:44:03 minidsp-shd go-librespot[3817]: time="2025-05-13T10:44:03-06:00" level=debug msg="stored credentials not found" May 13 10:44:03 minidsp-shd go-librespot[3817]: time="2025-05-13T10:44:03-06:00" level=info msg="api server listening on 127.0.0.1:9879" May 13 10:44:03 minidsp-shd volumio[702]: info: Initializing connection to go-librespot Websocket May 13 10:44:03 minidsp-shd go-librespot[3817]: time="2025-05-13T10:44:03-06:00" level=debug msg="new websocket client" May 13 10:44:03 minidsp-shd volumio[702]: info: Connection to go-librespot Websocket established May 13 10:44:03 minidsp-shd volumio[702]: info: Preload queue cleared May 13 10:44:04 minidsp-shd go-librespot[3817]: time="2025-05-13T10:44:04-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]" May 13 10:44:04 minidsp-shd go-librespot[3817]: time="2025-05-13T10:44:04-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]" May 13 10:44:04 minidsp-shd go-librespot[3817]: time="2025-05-13T10:44:04-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]" May 13 10:44:04 minidsp-shd go-librespot[3817]: time="2025-05-13T10:44:04-06:00" level=info msg="zeroconf server listening on port 38523" May 13 10:44:04 minidsp-shd go-librespot[3817]: time="2025-05-13T10:44:04-06:00" level=debug msg="obtained new client token: AAD5ECESwxljI8bXS0KWJe3iHiWRfZMefWu08/MvSQzqkmtdqucehpLH/thuJjc5NIRiRF5gb4TFxksG3xF32aUK+P4nF29H7pBnIY2bYtbEkBxwKER6nry8vTGznEnoKzi3pgmkO0RXj+fBSN5+jEPd0YZ56qNZSdJCGjED6x466v7LLotymg9RHYYfd7XUyoEe9QTFL3PQYn2C1XBdsqO8D//MxkoOJBHSMWxQTfrZu7f4Iv4t5U4=" May 13 10:44:04 minidsp-shd go-librespot[3817]: time="2025-05-13T10:44:04-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" May 13 10:44:04 minidsp-shd go-librespot[3817]: time="2025-05-13T10:44:04-06:00" level=debug msg="completed keyexchange" May 13 10:44:04 minidsp-shd go-librespot[3817]: time="2025-05-13T10:44:04-06:00" level=debug msg="completed challenge" May 13 10:44:04 minidsp-shd go-librespot[3817]: time="2025-05-13T10:44:04-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 " May 13 10:44:04 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 13 10:44:04 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 13 10:44:04 minidsp-shd volumio[702]: info: Connection to go-librespot Websocket closed May 13 10:44:06 minidsp-shd volumio[702]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri May 13 10:44:06 minidsp-shd volumio[702]: info: In handleBrowseUri, curUri=spotify:album:02R7PREL8nCr02CEYLy7YH May 13 10:44:06 minidsp-shd volumio[702]: info: Getting Spotify volume May 13 10:44:06 minidsp-shd volumio[702]: (node:702) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 May 13 10:44:06 minidsp-shd volumio[702]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) May 13 10:44:06 minidsp-shd volumio[702]: (node:702) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 51) May 13 10:44:06 minidsp-shd volumio[702]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 May 13 10:44:06 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioGetState May 13 10:44:06 minidsp-shd volumio[702]: info: CorePlayQueue::getTrack 4 May 13 10:44:06 minidsp-shd volumio[702]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 May 13 10:44:07 minidsp-shd volumio[702]: info: Initializing connection to go-librespot Websocket May 13 10:44:07 minidsp-shd volumio[702]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 13 10:44:07 minidsp-shd volumio[702]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri May 13 10:44:07 minidsp-shd volumio[702]: info: In handleBrowseUri, curUri=spotify:album:5XaRuw01PrWs2c2MvRIltv May 13 10:44:07 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 13 10:44:07 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 155. May 13 10:44:07 minidsp-shd systemd[1]: Stopped go-librespot Daemon. May 13 10:44:07 minidsp-shd systemd[1]: Started go-librespot Daemon. May 13 10:44:07 minidsp-shd go-librespot[3827]: go-librespot daemon starting... May 13 10:44:07 minidsp-shd go-librespot[3827]: time="2025-05-13T10:44:07-06:00" level=info msg="running go-librespot 0.2.0" May 13 10:44:07 minidsp-shd go-librespot[3827]: time="2025-05-13T10:44:07-06:00" level=debug msg="app state loaded" May 13 10:44:07 minidsp-shd go-librespot[3827]: time="2025-05-13T10:44:07-06:00" level=debug msg="stored credentials not found" May 13 10:44:07 minidsp-shd go-librespot[3827]: time="2025-05-13T10:44:07-06:00" level=info msg="api server listening on 127.0.0.1:9879" May 13 10:44:07 minidsp-shd volumio[702]: info: Preload queue cleared May 13 10:44:08 minidsp-shd go-librespot[3827]: time="2025-05-13T10:44:08-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]" May 13 10:44:08 minidsp-shd go-librespot[3827]: time="2025-05-13T10:44:08-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]" May 13 10:44:08 minidsp-shd go-librespot[3827]: time="2025-05-13T10:44:08-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]" May 13 10:44:08 minidsp-shd go-librespot[3827]: time="2025-05-13T10:44:08-06:00" level=info msg="zeroconf server listening on port 37747" May 13 10:44:08 minidsp-shd go-librespot[3827]: time="2025-05-13T10:44:08-06:00" level=debug msg="obtained new client token: AACchYrI9yKCUM8IjxEMTLmCQEOFRjkeTg6wHMamcX1CjCUiqJebtHAORdSpWWrznpMyH1ANlPoEXFxrRiqSwTmrG3hayRzIVaFDTEE5UVqTS0k/C9+FB9vyxqu3ScIjacjHMjkkcJsHCVk0SnjoqBUTTZbFTZFfRSPBJM2XdgFAQKWun7JDw96nsxvTIJx0fGV0DEBJNsk+HSOtCPM41qdabsP01zNMjy7aFG0X8G5a80Mx6cGsIGI=" May 13 10:44:08 minidsp-shd go-librespot[3827]: time="2025-05-13T10:44:08-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" May 13 10:44:08 minidsp-shd go-librespot[3827]: time="2025-05-13T10:44:08-06:00" level=debug msg="completed keyexchange" May 13 10:44:08 minidsp-shd go-librespot[3827]: time="2025-05-13T10:44:08-06:00" level=debug msg="completed challenge" May 13 10:44:08 minidsp-shd volumio[702]: info: Preload queue cleared May 13 10:44:08 minidsp-shd go-librespot[3827]: time="2025-05-13T10:44:08-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 " May 13 10:44:08 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 13 10:44:08 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 13 10:44:10 minidsp-shd volumio[702]: info: Initializing connection to go-librespot Websocket May 13 10:44:10 minidsp-shd volumio[702]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 13 10:44:10 minidsp-shd volumio[702]: info: Preload queue cleared May 13 10:44:10 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioReplaceandPlayItems May 13 10:44:10 minidsp-shd volumio[702]: info: CoreStateMachine::ClearQueue May 13 10:44:10 minidsp-shd volumio[702]: info: CoreStateMachine::stop May 13 10:44:10 minidsp-shd volumio[702]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 10:44:10 minidsp-shd volumio[702]: info: CorePlayQueue::clearPlayQueue May 13 10:44:10 minidsp-shd volumio[702]: info: CorePlayQueue::saveQueue May 13 10:44:10 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioPushQueue May 13 10:44:10 minidsp-shd volumio[702]: info: CoreStateMachine::addQueueItems May 13 10:44:10 minidsp-shd volumio[702]: info: CorePlayQueue::addQueueItems May 13 10:44:10 minidsp-shd volumio[702]: info: Preload queue cleared May 13 10:44:10 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:2L5mMhoCDANMkKlcRqRsPz May 13 10:44:10 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:2L5mMhoCDANMkKlcRqRsPz May 13 10:44:10 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:79wnqe4OlC0bN4z2FcsNvl May 13 10:44:10 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:79wnqe4OlC0bN4z2FcsNvl May 13 10:44:10 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:7fJoc5cbWxRcIOwsHvm7ms May 13 10:44:10 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:7fJoc5cbWxRcIOwsHvm7ms May 13 10:44:10 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:4duklrpXWKDPKrIYiomZgN May 13 10:44:10 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:4duklrpXWKDPKrIYiomZgN May 13 10:44:10 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:06MhzF9knuFgrCWEbWdLFZ May 13 10:44:10 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:06MhzF9knuFgrCWEbWdLFZ May 13 10:44:10 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:7u4a6OKdvj6iCT4sBcig1y May 13 10:44:10 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:7u4a6OKdvj6iCT4sBcig1y May 13 10:44:10 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:4THamLTyzH754GI9jDtbfJ May 13 10:44:10 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:4THamLTyzH754GI9jDtbfJ May 13 10:44:10 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:5xNUXOw963fZ5kdN16kpYA May 13 10:44:10 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:5xNUXOw963fZ5kdN16kpYA May 13 10:44:10 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:0rjPDPKMQpkUlYSMDTp73x May 13 10:44:10 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:0rjPDPKMQpkUlYSMDTp73x May 13 10:44:10 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:2jg6qxBqzovdbrWzAYZWcT May 13 10:44:10 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:2jg6qxBqzovdbrWzAYZWcT May 13 10:44:10 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:3diTM43SZ4ikeemWerniDH May 13 10:44:10 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:3diTM43SZ4ikeemWerniDH May 13 10:44:10 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:1LE0rdcbn9R6KPQyIQsAbO May 13 10:44:10 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:1LE0rdcbn9R6KPQyIQsAbO May 13 10:44:10 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:3M1N2ihFSzcP7XVc9PYlBZ May 13 10:44:10 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:3M1N2ihFSzcP7XVc9PYlBZ May 13 10:44:10 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioPushQueue May 13 10:44:10 minidsp-shd volumio[702]: info: CorePlayQueue::saveQueue May 13 10:44:11 minidsp-shd volumio[702]: info: CoreStateMachine::updateTrackBlock May 13 10:44:11 minidsp-shd volumio[702]: info: CorePlayQueue::getTrackBlock May 13 10:44:11 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioPlay May 13 10:44:11 minidsp-shd volumio[702]: info: CoreStateMachine::play index 3 May 13 10:44:11 minidsp-shd volumio[702]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 10:44:11 minidsp-shd volumio[702]: info: CoreStateMachine::stop May 13 10:44:11 minidsp-shd volumio[702]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 10:44:11 minidsp-shd volumio[702]: info: CoreStateMachine::play index undefined May 13 10:44:11 minidsp-shd volumio[702]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 10:44:11 minidsp-shd volumio[702]: info: CorePlayQueue::getTrack 3 May 13 10:44:11 minidsp-shd volumio[702]: info: CoreStateMachine::startPlaybackTimer May 13 10:44:11 minidsp-shd volumio[702]: info: CorePlayQueue::getTrack 3 May 13 10:44:11 minidsp-shd volumio[702]: info: [1747154651010] ControllerSpotify::clearAddPlayTrack May 13 10:44:11 minidsp-shd volumio[702]: info: Sending Spotify command with payload to local API: /player/play May 13 10:44:11 minidsp-shd volumio[702]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 May 13 10:44:11 minidsp-shd volumio[702]: info: Preload queue cleared May 13 10:44:11 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioReplaceandPlayItems May 13 10:44:11 minidsp-shd volumio[702]: info: CoreStateMachine::ClearQueue May 13 10:44:11 minidsp-shd volumio[702]: info: CoreStateMachine::stop May 13 10:44:11 minidsp-shd volumio[702]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 10:44:11 minidsp-shd volumio[702]: info: CorePlayQueue::clearPlayQueue May 13 10:44:11 minidsp-shd volumio[702]: info: CorePlayQueue::saveQueue May 13 10:44:11 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioPushQueue May 13 10:44:11 minidsp-shd volumio[702]: info: CoreStateMachine::addQueueItems May 13 10:44:11 minidsp-shd volumio[702]: info: CorePlayQueue::addQueueItems May 13 10:44:11 minidsp-shd volumio[702]: info: Preload queue cleared May 13 10:44:11 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:2L5mMhoCDANMkKlcRqRsPz May 13 10:44:11 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:2L5mMhoCDANMkKlcRqRsPz May 13 10:44:11 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:79wnqe4OlC0bN4z2FcsNvl May 13 10:44:11 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:79wnqe4OlC0bN4z2FcsNvl May 13 10:44:11 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:7fJoc5cbWxRcIOwsHvm7ms May 13 10:44:11 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:7fJoc5cbWxRcIOwsHvm7ms May 13 10:44:11 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:4duklrpXWKDPKrIYiomZgN May 13 10:44:11 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:4duklrpXWKDPKrIYiomZgN May 13 10:44:11 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:06MhzF9knuFgrCWEbWdLFZ May 13 10:44:11 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:06MhzF9knuFgrCWEbWdLFZ May 13 10:44:11 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:7u4a6OKdvj6iCT4sBcig1y May 13 10:44:11 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:7u4a6OKdvj6iCT4sBcig1y May 13 10:44:11 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:4THamLTyzH754GI9jDtbfJ May 13 10:44:11 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:4THamLTyzH754GI9jDtbfJ May 13 10:44:11 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:5xNUXOw963fZ5kdN16kpYA May 13 10:44:11 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:5xNUXOw963fZ5kdN16kpYA May 13 10:44:11 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:0rjPDPKMQpkUlYSMDTp73x May 13 10:44:11 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:0rjPDPKMQpkUlYSMDTp73x May 13 10:44:11 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:2jg6qxBqzovdbrWzAYZWcT May 13 10:44:11 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:2jg6qxBqzovdbrWzAYZWcT May 13 10:44:11 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:3diTM43SZ4ikeemWerniDH May 13 10:44:11 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:3diTM43SZ4ikeemWerniDH May 13 10:44:11 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:1LE0rdcbn9R6KPQyIQsAbO May 13 10:44:11 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:1LE0rdcbn9R6KPQyIQsAbO May 13 10:44:11 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:3M1N2ihFSzcP7XVc9PYlBZ May 13 10:44:11 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:3M1N2ihFSzcP7XVc9PYlBZ May 13 10:44:11 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioPushQueue May 13 10:44:11 minidsp-shd volumio[702]: info: CorePlayQueue::saveQueue May 13 10:44:11 minidsp-shd volumio[702]: info: CoreStateMachine::updateTrackBlock May 13 10:44:11 minidsp-shd volumio[702]: info: CorePlayQueue::getTrackBlock May 13 10:44:11 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioPlay May 13 10:44:11 minidsp-shd volumio[702]: info: CoreStateMachine::play index 3 May 13 10:44:11 minidsp-shd volumio[702]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 10:44:11 minidsp-shd volumio[702]: info: CoreStateMachine::stop May 13 10:44:11 minidsp-shd volumio[702]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 10:44:11 minidsp-shd volumio[702]: info: CoreStateMachine::play index undefined May 13 10:44:11 minidsp-shd volumio[702]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 10:44:11 minidsp-shd volumio[702]: info: CorePlayQueue::getTrack 3 May 13 10:44:11 minidsp-shd volumio[702]: info: CoreStateMachine::startPlaybackTimer May 13 10:44:11 minidsp-shd volumio[702]: info: CorePlayQueue::getTrack 3 May 13 10:44:11 minidsp-shd volumio[702]: info: [1747154651550] ControllerSpotify::clearAddPlayTrack May 13 10:44:11 minidsp-shd volumio[702]: info: Sending Spotify command with payload to local API: /player/play May 13 10:44:11 minidsp-shd volumio[702]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 May 13 10:44:11 minidsp-shd volumio[702]: info: Preload queue cleared May 13 10:44:11 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioReplaceandPlayItems May 13 10:44:11 minidsp-shd volumio[702]: info: CoreStateMachine::ClearQueue May 13 10:44:11 minidsp-shd volumio[702]: info: CoreStateMachine::stop May 13 10:44:11 minidsp-shd volumio[702]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 10:44:11 minidsp-shd volumio[702]: info: CorePlayQueue::clearPlayQueue May 13 10:44:11 minidsp-shd volumio[702]: info: CorePlayQueue::saveQueue May 13 10:44:11 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioPushQueue May 13 10:44:11 minidsp-shd volumio[702]: info: CoreStateMachine::addQueueItems May 13 10:44:11 minidsp-shd volumio[702]: info: CorePlayQueue::addQueueItems May 13 10:44:11 minidsp-shd volumio[702]: info: Preload queue cleared May 13 10:44:11 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:2L5mMhoCDANMkKlcRqRsPz May 13 10:44:11 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:2L5mMhoCDANMkKlcRqRsPz May 13 10:44:11 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:79wnqe4OlC0bN4z2FcsNvl May 13 10:44:11 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:79wnqe4OlC0bN4z2FcsNvl May 13 10:44:11 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:7fJoc5cbWxRcIOwsHvm7ms May 13 10:44:11 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:7fJoc5cbWxRcIOwsHvm7ms May 13 10:44:11 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:4duklrpXWKDPKrIYiomZgN May 13 10:44:11 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:4duklrpXWKDPKrIYiomZgN May 13 10:44:11 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:06MhzF9knuFgrCWEbWdLFZ May 13 10:44:11 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:06MhzF9knuFgrCWEbWdLFZ May 13 10:44:11 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:7u4a6OKdvj6iCT4sBcig1y May 13 10:44:11 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:7u4a6OKdvj6iCT4sBcig1y May 13 10:44:11 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:4THamLTyzH754GI9jDtbfJ May 13 10:44:11 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:4THamLTyzH754GI9jDtbfJ May 13 10:44:11 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:5xNUXOw963fZ5kdN16kpYA May 13 10:44:11 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:5xNUXOw963fZ5kdN16kpYA May 13 10:44:11 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:0rjPDPKMQpkUlYSMDTp73x May 13 10:44:11 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:0rjPDPKMQpkUlYSMDTp73x May 13 10:44:11 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:2jg6qxBqzovdbrWzAYZWcT May 13 10:44:11 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:2jg6qxBqzovdbrWzAYZWcT May 13 10:44:11 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:3diTM43SZ4ikeemWerniDH May 13 10:44:11 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:3diTM43SZ4ikeemWerniDH May 13 10:44:11 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:1LE0rdcbn9R6KPQyIQsAbO May 13 10:44:11 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:1LE0rdcbn9R6KPQyIQsAbO May 13 10:44:11 minidsp-shd volumio[702]: info: Adding Item to queue: spotify:track:3M1N2ihFSzcP7XVc9PYlBZ May 13 10:44:11 minidsp-shd volumio[702]: info: Using cached record of: spotify:track:3M1N2ihFSzcP7XVc9PYlBZ May 13 10:44:11 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioPushQueue May 13 10:44:11 minidsp-shd volumio[702]: info: CorePlayQueue::saveQueue May 13 10:44:11 minidsp-shd volumio[702]: info: CoreStateMachine::updateTrackBlock May 13 10:44:11 minidsp-shd volumio[702]: info: CorePlayQueue::getTrackBlock May 13 10:44:11 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioPlay May 13 10:44:11 minidsp-shd volumio[702]: info: CoreStateMachine::play index 3 May 13 10:44:11 minidsp-shd volumio[702]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 10:44:11 minidsp-shd volumio[702]: info: CoreStateMachine::stop May 13 10:44:11 minidsp-shd volumio[702]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 10:44:11 minidsp-shd volumio[702]: info: CoreStateMachine::play index undefined May 13 10:44:11 minidsp-shd volumio[702]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 10:44:11 minidsp-shd volumio[702]: info: CorePlayQueue::getTrack 3 May 13 10:44:11 minidsp-shd volumio[702]: info: CoreStateMachine::startPlaybackTimer May 13 10:44:11 minidsp-shd volumio[702]: info: CorePlayQueue::getTrack 3 May 13 10:44:11 minidsp-shd volumio[702]: info: [1747154651817] ControllerSpotify::clearAddPlayTrack May 13 10:44:11 minidsp-shd volumio[702]: info: Sending Spotify command with payload to local API: /player/play May 13 10:44:11 minidsp-shd volumio[702]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 May 13 10:44:11 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 13 10:44:11 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 156. May 13 10:44:11 minidsp-shd systemd[1]: Stopped go-librespot Daemon. May 13 10:44:11 minidsp-shd systemd[1]: Started go-librespot Daemon. May 13 10:44:11 minidsp-shd go-librespot[3835]: go-librespot daemon starting... May 13 10:44:12 minidsp-shd go-librespot[3835]: time="2025-05-13T10:44:12-06:00" level=info msg="running go-librespot 0.2.0" May 13 10:44:12 minidsp-shd go-librespot[3835]: time="2025-05-13T10:44:12-06:00" level=debug msg="app state loaded" May 13 10:44:12 minidsp-shd go-librespot[3835]: time="2025-05-13T10:44:12-06:00" level=debug msg="stored credentials not found" May 13 10:44:12 minidsp-shd go-librespot[3835]: time="2025-05-13T10:44:12-06:00" level=info msg="api server listening on 127.0.0.1:9879" May 13 10:44:12 minidsp-shd go-librespot[3835]: time="2025-05-13T10:44:12-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]" May 13 10:44:12 minidsp-shd go-librespot[3835]: time="2025-05-13T10:44:12-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]" May 13 10:44:12 minidsp-shd go-librespot[3835]: time="2025-05-13T10:44:12-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]" May 13 10:44:12 minidsp-shd go-librespot[3835]: time="2025-05-13T10:44:12-06:00" level=info msg="zeroconf server listening on port 41875" May 13 10:44:12 minidsp-shd go-librespot[3835]: time="2025-05-13T10:44:12-06:00" level=debug msg="obtained new client token: AAD4i2/OycY9QzwhdnwE6ZXJOxjBUfND8mrpEFM0ZyJKIMle+xew0kdp8aPz33OFD55MreQUTnxu7bFjN4KKbCjjrNKiINhxA/fZc28sHySnSwb52BGS6u9HZy53Q/UrGgTFjmRXuXOeNwOtzriw0/y+zmW92NsTRYgwbYbKjB3gvNR/UxSU+KHE1VHzjO9KrWmh42/NlFY9z8FVUrF3bsCYaOB0Ac9RvJlGD2vZM9tV4kSCi49nYRI=" May 13 10:44:12 minidsp-shd go-librespot[3835]: time="2025-05-13T10:44:12-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" May 13 10:44:12 minidsp-shd go-librespot[3835]: time="2025-05-13T10:44:12-06:00" level=debug msg="completed keyexchange" May 13 10:44:12 minidsp-shd go-librespot[3835]: time="2025-05-13T10:44:12-06:00" level=debug msg="completed challenge" May 13 10:44:12 minidsp-shd go-librespot[3835]: time="2025-05-13T10:44:12-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 " May 13 10:44:12 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 13 10:44:12 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 13 10:44:13 minidsp-shd volumio[702]: info: Initializing connection to go-librespot Websocket May 13 10:44:13 minidsp-shd volumio[702]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 13 10:44:16 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 13 10:44:16 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 157. May 13 10:44:16 minidsp-shd systemd[1]: Stopped go-librespot Daemon. May 13 10:44:16 minidsp-shd systemd[1]: Started go-librespot Daemon. May 13 10:44:16 minidsp-shd go-librespot[3843]: go-librespot daemon starting... May 13 10:44:16 minidsp-shd go-librespot[3843]: time="2025-05-13T10:44:16-06:00" level=info msg="running go-librespot 0.2.0" May 13 10:44:16 minidsp-shd go-librespot[3843]: time="2025-05-13T10:44:16-06:00" level=debug msg="app state loaded" May 13 10:44:16 minidsp-shd go-librespot[3843]: time="2025-05-13T10:44:16-06:00" level=debug msg="stored credentials not found" May 13 10:44:16 minidsp-shd go-librespot[3843]: time="2025-05-13T10:44:16-06:00" level=info msg="api server listening on 127.0.0.1:9879" May 13 10:44:16 minidsp-shd volumio[702]: info: Initializing connection to go-librespot Websocket May 13 10:44:16 minidsp-shd go-librespot[3843]: time="2025-05-13T10:44:16-06:00" level=debug msg="new websocket client" May 13 10:44:16 minidsp-shd volumio[702]: info: Connection to go-librespot Websocket established May 13 10:44:16 minidsp-shd go-librespot[3843]: time="2025-05-13T10:44:16-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]" May 13 10:44:16 minidsp-shd go-librespot[3843]: time="2025-05-13T10:44:16-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]" May 13 10:44:16 minidsp-shd go-librespot[3843]: time="2025-05-13T10:44:16-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]" May 13 10:44:16 minidsp-shd go-librespot[3843]: time="2025-05-13T10:44:16-06:00" level=info msg="zeroconf server listening on port 35817" May 13 10:44:16 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioPrevious May 13 10:44:16 minidsp-shd volumio[702]: info: CoreStateMachine::previous May 13 10:44:16 minidsp-shd volumio[702]: info: CoreStateMachine::updateTrackBlock May 13 10:44:16 minidsp-shd volumio[702]: info: CorePlayQueue::getTrackBlock May 13 10:44:16 minidsp-shd volumio[702]: info: CoreStateMachine::pushState May 13 10:44:16 minidsp-shd volumio[702]: info: CorePlayQueue::getTrack 2 May 13 10:44:16 minidsp-shd volumio[702]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 13 10:44:16 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioPushState May 13 10:44:16 minidsp-shd volumio[702]: info: MRS: Pushing multiroomSync output update for this device May 13 10:44:16 minidsp-shd volumio[702]: info: MRS: Pushing multiroomSync output May 13 10:44:16 minidsp-shd volumio[702]: info: MRS: Pushing multiroomSync output update for this device May 13 10:44:16 minidsp-shd volumio[702]: info: MRS: Pushing multiroomSync output May 13 10:44:16 minidsp-shd go-librespot[3843]: time="2025-05-13T10:44:16-06:00" level=debug msg="obtained new client token: AADBJXgL0V0e5CCkTm6UgEXnPXbBSYmFXDRpl+qEEomCVW7FG+xzFxxw3v8AolBwV7v4iKRlulJTg+zvd/LV+vVlWu0cRRDtXbnSgSuAgkF5zuPV/nfVryzmnbA7H5GGtTYLobo0L4JS0sCSzMhJjBZNkSboZtW2R9CYD1GHksg28IsUpND3ii0j2JcKHVbpm2cfxhB6MI7m9Esm7WpraBNuubu1O5YlgasKDRxpBIpVFBF1qvnxBC8=" May 13 10:44:17 minidsp-shd volumio[702]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 May 13 10:44:17 minidsp-shd go-librespot[3843]: time="2025-05-13T10:44:17-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" May 13 10:44:17 minidsp-shd go-librespot[3843]: time="2025-05-13T10:44:17-06:00" level=debug msg="completed keyexchange" May 13 10:44:17 minidsp-shd go-librespot[3843]: time="2025-05-13T10:44:17-06:00" level=debug msg="completed challenge" May 13 10:44:17 minidsp-shd go-librespot[3843]: time="2025-05-13T10:44:17-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 " May 13 10:44:17 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 13 10:44:17 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 13 10:44:17 minidsp-shd volumio[702]: info: Connection to go-librespot Websocket closed May 13 10:44:19 minidsp-shd volumio[702]: info: Getting Spotify volume May 13 10:44:19 minidsp-shd volumio[702]: (node:702) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 May 13 10:44:19 minidsp-shd volumio[702]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) May 13 10:44:19 minidsp-shd volumio[702]: (node:702) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 52) May 13 10:44:19 minidsp-shd volumio[702]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 May 13 10:44:19 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioGetState May 13 10:44:19 minidsp-shd volumio[702]: info: CorePlayQueue::getTrack 2 May 13 10:44:19 minidsp-shd volumio[702]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 May 13 10:44:20 minidsp-shd volumio[702]: info: Initializing connection to go-librespot Websocket May 13 10:44:20 minidsp-shd volumio[702]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 13 10:44:20 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 13 10:44:20 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 158. May 13 10:44:20 minidsp-shd systemd[1]: Stopped go-librespot Daemon. May 13 10:44:20 minidsp-shd systemd[1]: Started go-librespot Daemon. May 13 10:44:20 minidsp-shd go-librespot[3852]: go-librespot daemon starting... May 13 10:44:20 minidsp-shd go-librespot[3852]: time="2025-05-13T10:44:20-06:00" level=info msg="running go-librespot 0.2.0" May 13 10:44:20 minidsp-shd go-librespot[3852]: time="2025-05-13T10:44:20-06:00" level=debug msg="app state loaded" May 13 10:44:20 minidsp-shd go-librespot[3852]: time="2025-05-13T10:44:20-06:00" level=debug msg="stored credentials not found" May 13 10:44:20 minidsp-shd go-librespot[3852]: time="2025-05-13T10:44:20-06:00" level=info msg="api server listening on 127.0.0.1:9879" May 13 10:44:20 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioPlay May 13 10:44:20 minidsp-shd volumio[702]: info: CoreStateMachine::play index undefined May 13 10:44:20 minidsp-shd volumio[702]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 10:44:20 minidsp-shd volumio[702]: info: CorePlayQueue::getTrack 2 May 13 10:44:20 minidsp-shd volumio[702]: info: CoreStateMachine::startPlaybackTimer May 13 10:44:20 minidsp-shd volumio[702]: info: CorePlayQueue::getTrack 2 May 13 10:44:20 minidsp-shd volumio[702]: info: [1747154660588] ControllerSpotify::clearAddPlayTrack May 13 10:44:20 minidsp-shd volumio[702]: info: Sending Spotify command with payload to local API: /player/play May 13 10:44:20 minidsp-shd go-librespot[3852]: time="2025-05-13T10:44:20-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]" May 13 10:44:20 minidsp-shd go-librespot[3852]: time="2025-05-13T10:44:20-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]" May 13 10:44:20 minidsp-shd go-librespot[3852]: time="2025-05-13T10:44:20-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]" May 13 10:44:20 minidsp-shd go-librespot[3852]: time="2025-05-13T10:44:20-06:00" level=info msg="zeroconf server listening on port 39681" May 13 10:44:21 minidsp-shd go-librespot[3852]: time="2025-05-13T10:44:21-06:00" level=debug msg="obtained new client token: AABxJUE5Hw932yebl9hEQko7aMk6DBVbh+VL0RCN2u1GRPLsZN2SLvl06m1Eh1qL2X/deQ5302SqXaAKuZVnw+nK4AwSyZ2QKPinLcrRpsn/yW8LJ8QEnXPzi0/T6AKJJ8t1Q6tCqpn8CNTxv2B6A7UZtY1bzHLc4uZ9+0xJOlshQHr3OmvW4gWyslv+S2gx5TbyXeoXlCYuUox7pt4VQpytwbS/INa6wDCeslu+DHrld35s9wSL" May 13 10:44:21 minidsp-shd go-librespot[3852]: time="2025-05-13T10:44:21-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" May 13 10:44:21 minidsp-shd go-librespot[3852]: time="2025-05-13T10:44:21-06:00" level=debug msg="completed keyexchange" May 13 10:44:21 minidsp-shd go-librespot[3852]: time="2025-05-13T10:44:21-06:00" level=debug msg="completed challenge" May 13 10:44:21 minidsp-shd go-librespot[3852]: time="2025-05-13T10:44:21-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 " May 13 10:44:21 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 13 10:44:21 minidsp-shd volumio[702]: error: Failed to send command to Spotify local API: /player/play: Error: socket hang up May 13 10:44:21 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 13 10:44:23 minidsp-shd volumio[702]: info: Initializing connection to go-librespot Websocket May 13 10:44:23 minidsp-shd volumio[702]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 13 10:44:24 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 13 10:44:24 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 159. May 13 10:44:24 minidsp-shd systemd[1]: Stopped go-librespot Daemon. May 13 10:44:24 minidsp-shd systemd[1]: Started go-librespot Daemon. May 13 10:44:24 minidsp-shd go-librespot[3860]: go-librespot daemon starting... May 13 10:44:24 minidsp-shd go-librespot[3860]: time="2025-05-13T10:44:24-06:00" level=info msg="running go-librespot 0.2.0" May 13 10:44:24 minidsp-shd go-librespot[3860]: time="2025-05-13T10:44:24-06:00" level=debug msg="app state loaded" May 13 10:44:24 minidsp-shd go-librespot[3860]: time="2025-05-13T10:44:24-06:00" level=debug msg="stored credentials not found" May 13 10:44:24 minidsp-shd go-librespot[3860]: time="2025-05-13T10:44:24-06:00" level=info msg="api server listening on 127.0.0.1:9879" May 13 10:44:24 minidsp-shd go-librespot[3860]: time="2025-05-13T10:44:24-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]" May 13 10:44:24 minidsp-shd go-librespot[3860]: time="2025-05-13T10:44:24-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]" May 13 10:44:24 minidsp-shd go-librespot[3860]: time="2025-05-13T10:44:24-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]" May 13 10:44:24 minidsp-shd go-librespot[3860]: time="2025-05-13T10:44:24-06:00" level=info msg="zeroconf server listening on port 43047" May 13 10:44:25 minidsp-shd go-librespot[3860]: time="2025-05-13T10:44:25-06:00" level=debug msg="obtained new client token: AACGNi91sAZhav4zDhNv/cPb2SQLTCfCWw1BMU6R7Z4t+GlXSE8Z7sNhv5kiC0So2IDBqPTf/7RbKvHaeSHD/g3RynDJz7lRqSmFjoAZQ8w81AWF9pZBcX3vgO7rG9V93LgE1TUOcqME8+QIPWst6RafXb6ixMZWaaXjcXkT3Xh7Fh1xuhP2yEHQm+R9A19NLzd0PApM25ep9WHT7zefjs5KQwmbpUaDi6PV63cEtSAogRMcbTHs" May 13 10:44:25 minidsp-shd go-librespot[3860]: time="2025-05-13T10:44:25-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" May 13 10:44:25 minidsp-shd go-librespot[3860]: time="2025-05-13T10:44:25-06:00" level=debug msg="completed keyexchange" May 13 10:44:25 minidsp-shd go-librespot[3860]: time="2025-05-13T10:44:25-06:00" level=debug msg="completed challenge" May 13 10:44:25 minidsp-shd go-librespot[3860]: time="2025-05-13T10:44:25-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 " May 13 10:44:25 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 13 10:44:25 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 13 10:44:26 minidsp-shd volumio[702]: info: Initializing connection to go-librespot Websocket May 13 10:44:26 minidsp-shd volumio[702]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 13 10:44:28 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 13 10:44:28 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 160. May 13 10:44:28 minidsp-shd systemd[1]: Stopped go-librespot Daemon. May 13 10:44:28 minidsp-shd systemd[1]: Started go-librespot Daemon. May 13 10:44:28 minidsp-shd go-librespot[3869]: go-librespot daemon starting... May 13 10:44:28 minidsp-shd go-librespot[3869]: time="2025-05-13T10:44:28-06:00" level=info msg="running go-librespot 0.2.0" May 13 10:44:28 minidsp-shd go-librespot[3869]: time="2025-05-13T10:44:28-06:00" level=debug msg="app state loaded" May 13 10:44:28 minidsp-shd go-librespot[3869]: time="2025-05-13T10:44:28-06:00" level=debug msg="stored credentials not found" May 13 10:44:28 minidsp-shd go-librespot[3869]: time="2025-05-13T10:44:28-06:00" level=info msg="api server listening on 127.0.0.1:9879" May 13 10:44:29 minidsp-shd go-librespot[3869]: time="2025-05-13T10:44:29-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]" May 13 10:44:29 minidsp-shd go-librespot[3869]: time="2025-05-13T10:44:29-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]" May 13 10:44:29 minidsp-shd go-librespot[3869]: time="2025-05-13T10:44:29-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]" May 13 10:44:29 minidsp-shd go-librespot[3869]: time="2025-05-13T10:44:29-06:00" level=info msg="zeroconf server listening on port 45679" May 13 10:44:29 minidsp-shd volumio[702]: info: Initializing connection to go-librespot Websocket May 13 10:44:29 minidsp-shd go-librespot[3869]: time="2025-05-13T10:44:29-06:00" level=debug msg="new websocket client" May 13 10:44:29 minidsp-shd volumio[702]: info: Connection to go-librespot Websocket established May 13 10:44:29 minidsp-shd go-librespot[3869]: time="2025-05-13T10:44:29-06:00" level=debug msg="obtained new client token: AACgao4tOwuVXwJRJAxfwE2pgiZP2fysmmllLe8X+aLg9srtiKj6DeRhMBzNenJX0VM3BgV5hA4+DStg1qsYv44KjxsWzGbHN/RZbpHHWjzxeRnr/XfdD7kVtIFgjcxIClfKn/kRRVE66f3u4huF7yvU4Ta+1y7RjDlwFnK9xISx8MetyhK0xI3h8Hazc1i1LFl4+gyyX57oklLUnUxwpwH/QVHFOUQWeYU5j19I5XWmReQUJc4N/Sc=" May 13 10:44:29 minidsp-shd go-librespot[3869]: time="2025-05-13T10:44:29-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" May 13 10:44:29 minidsp-shd go-librespot[3869]: time="2025-05-13T10:44:29-06:00" level=debug msg="completed keyexchange" May 13 10:44:29 minidsp-shd go-librespot[3869]: time="2025-05-13T10:44:29-06:00" level=debug msg="completed challenge" May 13 10:44:29 minidsp-shd go-librespot[3869]: time="2025-05-13T10:44:29-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 " May 13 10:44:29 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 13 10:44:29 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 13 10:44:29 minidsp-shd volumio[702]: info: Connection to go-librespot Websocket closed May 13 10:44:32 minidsp-shd volumio[702]: info: Getting Spotify volume May 13 10:44:32 minidsp-shd volumio[702]: (node:702) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 May 13 10:44:32 minidsp-shd volumio[702]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) May 13 10:44:32 minidsp-shd volumio[702]: (node:702) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 53) May 13 10:44:32 minidsp-shd volumio[702]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 May 13 10:44:32 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioGetState May 13 10:44:32 minidsp-shd volumio[702]: info: CorePlayQueue::getTrack 2 May 13 10:44:32 minidsp-shd volumio[702]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 May 13 10:44:32 minidsp-shd volumio[702]: info: Initializing connection to go-librespot Websocket May 13 10:44:32 minidsp-shd volumio[702]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 13 10:44:32 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 13 10:44:32 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 161. May 13 10:44:32 minidsp-shd systemd[1]: Stopped go-librespot Daemon. May 13 10:44:32 minidsp-shd systemd[1]: Started go-librespot Daemon. May 13 10:44:32 minidsp-shd go-librespot[3877]: go-librespot daemon starting... May 13 10:44:32 minidsp-shd go-librespot[3877]: time="2025-05-13T10:44:32-06:00" level=info msg="running go-librespot 0.2.0" May 13 10:44:32 minidsp-shd go-librespot[3877]: time="2025-05-13T10:44:32-06:00" level=debug msg="app state loaded" May 13 10:44:32 minidsp-shd go-librespot[3877]: time="2025-05-13T10:44:32-06:00" level=debug msg="stored credentials not found" May 13 10:44:32 minidsp-shd go-librespot[3877]: time="2025-05-13T10:44:32-06:00" level=info msg="api server listening on 127.0.0.1:9879" May 13 10:44:33 minidsp-shd go-librespot[3877]: time="2025-05-13T10:44:33-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]" May 13 10:44:33 minidsp-shd go-librespot[3877]: time="2025-05-13T10:44:33-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]" May 13 10:44:33 minidsp-shd go-librespot[3877]: time="2025-05-13T10:44:33-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]" May 13 10:44:33 minidsp-shd go-librespot[3877]: time="2025-05-13T10:44:33-06:00" level=info msg="zeroconf server listening on port 42865" May 13 10:44:33 minidsp-shd go-librespot[3877]: time="2025-05-13T10:44:33-06:00" level=debug msg="obtained new client token: AADtfgCivs+cSWP36Gc2i2e4wEeoPnTKAjKFbKp3lAKX29JLJWvvoEudfh+BIc4dc9qNKWs+mEvCsK0Aw0kFzw1OBHAnvXMzEy6IPvA3mAthYiijUVVbBrymCfflZj/sD/+nGrq7hSH/dCMKqFjYF0pLOOPJhiz9NpDdeZCTOtNttO4WAgUzS4vltfJVj6Yr4diGl5Lik35aeM5fPrlOYrKc377cRW9mOfEYgvE6IPlyKPAgtmP4Mr0=" May 13 10:44:33 minidsp-shd go-librespot[3877]: time="2025-05-13T10:44:33-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" May 13 10:44:33 minidsp-shd go-librespot[3877]: time="2025-05-13T10:44:33-06:00" level=debug msg="completed keyexchange" May 13 10:44:33 minidsp-shd go-librespot[3877]: time="2025-05-13T10:44:33-06:00" level=debug msg="completed challenge" May 13 10:44:33 minidsp-shd go-librespot[3877]: time="2025-05-13T10:44: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 " May 13 10:44:33 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 13 10:44:33 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 13 10:44:35 minidsp-shd volumio[702]: info: Initializing connection to go-librespot Websocket May 13 10:44:35 minidsp-shd volumio[702]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 13 10:44:36 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 13 10:44:36 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 162. May 13 10:44:36 minidsp-shd systemd[1]: Stopped go-librespot Daemon. May 13 10:44:36 minidsp-shd systemd[1]: Started go-librespot Daemon. May 13 10:44:36 minidsp-shd go-librespot[3924]: go-librespot daemon starting... May 13 10:44:36 minidsp-shd go-librespot[3924]: time="2025-05-13T10:44:36-06:00" level=info msg="running go-librespot 0.2.0" May 13 10:44:36 minidsp-shd go-librespot[3924]: time="2025-05-13T10:44:36-06:00" level=debug msg="app state loaded" May 13 10:44:36 minidsp-shd go-librespot[3924]: time="2025-05-13T10:44:36-06:00" level=debug msg="stored credentials not found" May 13 10:44:36 minidsp-shd go-librespot[3924]: time="2025-05-13T10:44:36-06:00" level=info msg="api server listening on 127.0.0.1:9879" May 13 10:44:37 minidsp-shd go-librespot[3924]: time="2025-05-13T10:44:37-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]" May 13 10:44:37 minidsp-shd go-librespot[3924]: time="2025-05-13T10:44:37-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]" May 13 10:44:37 minidsp-shd go-librespot[3924]: time="2025-05-13T10:44:37-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]" May 13 10:44:37 minidsp-shd go-librespot[3924]: time="2025-05-13T10:44:37-06:00" level=info msg="zeroconf server listening on port 36467" May 13 10:44:37 minidsp-shd go-librespot[3924]: time="2025-05-13T10:44:37-06:00" level=debug msg="obtained new client token: AACOOvv5f2NW0s4BOG8LjiS2q0Nm3cxFCwkK/QBhAdorjVY6xs18v42iIsONBnmAliMpTEqgiTz/tGf7aQLvmRUimCYN9Hn5UFUd1tZv6jxCn8ahogO4/DdaWmyOr4QFpHqlPzg81ScogEmrzU9QQIeA6oG8bAg4JqpKUnIlCJyR43KRejRTNrAzcXSOmhGOOs7HX5QiQ/c4AZSfy0ebQJy6/SYhkau+evEmlU+clm6taznX0Yx/h9A=" May 13 10:44:37 minidsp-shd go-librespot[3924]: time="2025-05-13T10:44:37-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" May 13 10:44:37 minidsp-shd go-librespot[3924]: time="2025-05-13T10:44:37-06:00" level=debug msg="completed keyexchange" May 13 10:44:37 minidsp-shd go-librespot[3924]: time="2025-05-13T10:44:37-06:00" level=debug msg="completed challenge" May 13 10:44:37 minidsp-shd go-librespot[3924]: time="2025-05-13T10:44: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 " May 13 10:44:37 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 13 10:44:37 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 13 10:44:38 minidsp-shd volumio[702]: info: Initializing connection to go-librespot Websocket May 13 10:44:38 minidsp-shd volumio[702]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 13 10:44:40 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 13 10:44:40 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 163. May 13 10:44:40 minidsp-shd systemd[1]: Stopped go-librespot Daemon. May 13 10:44:40 minidsp-shd systemd[1]: Started go-librespot Daemon. May 13 10:44:40 minidsp-shd go-librespot[3932]: go-librespot daemon starting... May 13 10:44:40 minidsp-shd go-librespot[3932]: time="2025-05-13T10:44:40-06:00" level=info msg="running go-librespot 0.2.0" May 13 10:44:40 minidsp-shd go-librespot[3932]: time="2025-05-13T10:44:40-06:00" level=debug msg="app state loaded" May 13 10:44:40 minidsp-shd go-librespot[3932]: time="2025-05-13T10:44:40-06:00" level=debug msg="stored credentials not found" May 13 10:44:41 minidsp-shd go-librespot[3932]: time="2025-05-13T10:44:41-06:00" level=info msg="api server listening on 127.0.0.1:9879" May 13 10:44:41 minidsp-shd go-librespot[3932]: time="2025-05-13T10:44:41-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]" May 13 10:44:41 minidsp-shd go-librespot[3932]: time="2025-05-13T10:44:41-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]" May 13 10:44:41 minidsp-shd go-librespot[3932]: time="2025-05-13T10:44:41-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]" May 13 10:44:41 minidsp-shd go-librespot[3932]: time="2025-05-13T10:44:41-06:00" level=info msg="zeroconf server listening on port 42073" May 13 10:44:41 minidsp-shd volumio[702]: info: Initializing connection to go-librespot Websocket May 13 10:44:41 minidsp-shd go-librespot[3932]: time="2025-05-13T10:44:41-06:00" level=debug msg="new websocket client" May 13 10:44:41 minidsp-shd volumio[702]: info: Connection to go-librespot Websocket established May 13 10:44:41 minidsp-shd go-librespot[3932]: time="2025-05-13T10:44:41-06:00" level=debug msg="obtained new client token: AACVWIweZVoulNM1EXVcMhX60kuvfV0sLtxL4zi51sgMi7DPViWzRovbWFSJDYVb36iz9XmMLN5MbXatf1ZMytshKRbLvzKm5B31fXw+rKWuaF0OTUXEULee9PkmVkm0KQNhdnjXF7JxPRSzyPd+bdb/QPM3ytiA3BySri+qvkRZX4VS0xtH4Tpd0TJ5R4prvT8WRGLPa/xmiYI9OIXXKMMNdeqWL28QQIY03oTW1ol7QBtdKgYaCnA=" May 13 10:44:41 minidsp-shd go-librespot[3932]: time="2025-05-13T10:44:41-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" May 13 10:44:41 minidsp-shd go-librespot[3932]: time="2025-05-13T10:44:41-06:00" level=debug msg="completed keyexchange" May 13 10:44:41 minidsp-shd go-librespot[3932]: time="2025-05-13T10:44:41-06:00" level=debug msg="completed challenge" May 13 10:44:41 minidsp-shd go-librespot[3932]: time="2025-05-13T10:44: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 " May 13 10:44:41 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 13 10:44:41 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 13 10:44:41 minidsp-shd volumio[702]: info: Connection to go-librespot Websocket closed May 13 10:44:44 minidsp-shd volumio[702]: info: Getting Spotify volume May 13 10:44:44 minidsp-shd volumio[702]: (node:702) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 May 13 10:44:44 minidsp-shd volumio[702]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) May 13 10:44:44 minidsp-shd volumio[702]: (node:702) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 54) May 13 10:44:44 minidsp-shd volumio[702]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 May 13 10:44:44 minidsp-shd volumio[702]: info: CoreCommandRouter::volumioGetState May 13 10:44:44 minidsp-shd volumio[702]: info: CorePlayQueue::getTrack 2 May 13 10:44:44 minidsp-shd volumio[702]: SPOTIFY: RECEIVED VOLUMIO VOLUME 78 May 13 10:44:44 minidsp-shd volumio[702]: info: Initializing connection to go-librespot Websocket May 13 10:44:44 minidsp-shd volumio[702]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 13 10:44:45 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 13 10:44:45 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 164. May 13 10:44:45 minidsp-shd systemd[1]: Stopped go-librespot Daemon. May 13 10:44:45 minidsp-shd systemd[1]: Started go-librespot Daemon. May 13 10:44:45 minidsp-shd go-librespot[3940]: go-librespot daemon starting... May 13 10:44:45 minidsp-shd go-librespot[3940]: time="2025-05-13T10:44:45-06:00" level=info msg="running go-librespot 0.2.0" May 13 10:44:45 minidsp-shd go-librespot[3940]: time="2025-05-13T10:44:45-06:00" level=debug msg="app state loaded" May 13 10:44:45 minidsp-shd go-librespot[3940]: time="2025-05-13T10:44:45-06:00" level=debug msg="stored credentials not found" May 13 10:44:45 minidsp-shd go-librespot[3940]: time="2025-05-13T10:44:45-06:00" level=info msg="api server listening on 127.0.0.1:9879" May 13 10:44:45 minidsp-shd go-librespot[3940]: time="2025-05-13T10:44:45-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]" May 13 10:44:45 minidsp-shd go-librespot[3940]: time="2025-05-13T10:44:45-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]" May 13 10:44:45 minidsp-shd go-librespot[3940]: time="2025-05-13T10:44:45-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]" May 13 10:44:45 minidsp-shd go-librespot[3940]: time="2025-05-13T10:44:45-06:00" level=info msg="zeroconf server listening on port 39599" May 13 10:44:46 minidsp-shd go-librespot[3940]: time="2025-05-13T10:44:46-06:00" level=debug msg="obtained new client token: AAASKun1zo4KzwZgQfOpXbDPh0Vaxwn5cXEAv5M2G6XWcFii357qtHXF7UigDNSv09kbBQpi8yxSvzr7jPncQaKnootHX0GPVCOr7Vh2gyUcBDWm1lzKp3ur1ci9ha0j3CYFeJRaD3ol/kHu+rYG7tpakGx/ol+GM8ONXQOH71FveocKAF67proHsLaWe+bvab7Mrq+ZDll8ttzDNSMN1ciM51xJ6lT3zDvDKA7h2uIqIeI1WQiPT2I=" May 13 10:44:46 minidsp-shd go-librespot[3940]: time="2025-05-13T10:44:46-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" May 13 10:44:46 minidsp-shd go-librespot[3940]: time="2025-05-13T10:44:46-06:00" level=debug msg="completed keyexchange" May 13 10:44:46 minidsp-shd go-librespot[3940]: time="2025-05-13T10:44:46-06:00" level=debug msg="completed challenge" May 13 10:44:46 minidsp-shd go-librespot[3940]: time="2025-05-13T10:44:46-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 " May 13 10:44:46 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 13 10:44:46 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 13 10:44:47 minidsp-shd volumio[702]: info: Initializing connection to go-librespot Websocket May 13 10:44:47 minidsp-shd volumio[702]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 13 10:44:49 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 13 10:44:49 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 165. May 13 10:44:49 minidsp-shd systemd[1]: Stopped go-librespot Daemon. May 13 10:44:49 minidsp-shd systemd[1]: Started go-librespot Daemon. May 13 10:44:49 minidsp-shd go-librespot[3950]: go-librespot daemon starting... May 13 10:44:49 minidsp-shd go-librespot[3950]: time="2025-05-13T10:44:49-06:00" level=info msg="running go-librespot 0.2.0" May 13 10:44:49 minidsp-shd go-librespot[3950]: time="2025-05-13T10:44:49-06:00" level=debug msg="app state loaded" May 13 10:44:49 minidsp-shd go-librespot[3950]: time="2025-05-13T10:44:49-06:00" level=debug msg="stored credentials not found" May 13 10:44:49 minidsp-shd go-librespot[3950]: time="2025-05-13T10:44:49-06:00" level=info msg="api server listening on 127.0.0.1:9879" May 13 10:44:49 minidsp-shd go-librespot[3950]: time="2025-05-13T10:44: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]" May 13 10:44:49 minidsp-shd go-librespot[3950]: time="2025-05-13T10:44: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]" May 13 10:44:49 minidsp-shd go-librespot[3950]: time="2025-05-13T10:44: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]" May 13 10:44:49 minidsp-shd go-librespot[3950]: time="2025-05-13T10:44:49-06:00" level=info msg="zeroconf server listening on port 39443" May 13 10:44:50 minidsp-shd go-librespot[3950]: time="2025-05-13T10:44:50-06:00" level=debug msg="obtained new client token: AACXV7qyDmHaEOfAOprpqREowvXHkh/BhwOnL8ECfy3ro8tWvPt6w1nbjI2jdVEkuwEl54KO6KMrDT9Zhi55gll4/QnsLRNbnrC2dvGR/tqrjQg0sf+Qn6KIu27ChkCFuIXTR/SYoRpLS41jbVSQFL7Xp7HsdrRJH1n13j6VHDJLpnZDso3FvA7ceTmCHwcRBABc3Csa1n5UjRF6apI6GstuoF92p+MWRvRE8locyF2ms8p8qqKF" May 13 10:44:50 minidsp-shd go-librespot[3950]: time="2025-05-13T10:44:50-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" May 13 10:44:50 minidsp-shd go-librespot[3950]: time="2025-05-13T10:44:50-06:00" level=debug msg="completed keyexchange" May 13 10:44:50 minidsp-shd go-librespot[3950]: time="2025-05-13T10:44:50-06:00" level=debug msg="completed challenge" May 13 10:44:50 minidsp-shd go-librespot[3950]: time="2025-05-13T10:44:50-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 " May 13 10:44:50 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 13 10:44:50 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 13 10:44:50 minidsp-shd volumio[702]: info: Initializing connection to go-librespot Websocket May 13 10:44:50 minidsp-shd volumio[702]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 13 10:44:52 minidsp-shd volumio[702]: info: CoreCommandRouter::executeOnPlugin: multiroom , audioOutputPlay May 13 10:44:52 minidsp-shd volumio[702]: info: Error : CoreCommandRouter::executeOnPlugin: No method [audioOutputPlay] in plugin multiroom May 13 10:44:52 minidsp-shd volumio[702]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 13 10:44:52 minidsp-shd volumio[702]: TypeError: Cannot read property 'then' of undefined May 13 10:44:52 minidsp-shd volumio[702]: at outputs.audioOutputPlay (/volumio/app/plugins/audio_interface/outputs/index.js:367:9) May 13 10:44:52 minidsp-shd volumio[702]: at CoreCommandRouter.audioOutputPlay (/volumio/app/index.js:2249:30) May 13 10:44:52 minidsp-shd volumio[702]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1411:26) May 13 10:44:52 minidsp-shd volumio[702]: at Socket.emit (events.js:400:28) May 13 10:44:52 minidsp-shd volumio[702]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 May 13 10:44:52 minidsp-shd volumio[702]: at processTicksAndRejections (internal/process/task_queues.js:77:11) May 13 10:44:52 minidsp-shd volumio[702]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 13 10:44:53 minidsp-shd sudo[3967]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-13 10:43 May 13 10:44:53 minidsp-shd sudo[3967]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 10:44:53 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 13 10:44:53 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 166. May 13 10:44:53 minidsp-shd systemd[1]: Stopped go-librespot Daemon. May 13 10:44:53 minidsp-shd systemd[1]: Started go-librespot Daemon. May 13 10:44:53 minidsp-shd go-librespot[3969]: go-librespot daemon starting... May 13 10:44:53 minidsp-shd go-librespot[3969]: time="2025-05-13T10:44:53-06:00" level=info msg="running go-librespot 0.2.0" May 13 10:44:53 minidsp-shd go-librespot[3969]: time="2025-05-13T10:44:53-06:00" level=debug msg="app state loaded" May 13 10:44:53 minidsp-shd go-librespot[3969]: time="2025-05-13T10:44:53-06:00" level=debug msg="stored credentials not found" May 13 10:44:53 minidsp-shd go-librespot[3969]: time="2025-05-13T10:44:53-06:00" level=info msg="api server listening on 127.0.0.1:9879" 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"