-- Logs begin at Tue 2024-05-07 09:13:53 CST, end at Tue 2024-05-07 12:07:58 CST. --
May 07 12:06:00 minidsp-shd go-librespot[32350]: time="2024-05-07T12:06:00+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
May 07 12:06:00 minidsp-shd go-librespot[32350]: time="2024-05-07T12:06:00+08:00" level=debug msg="completed keyexchange"
May 07 12:06:01 minidsp-shd go-librespot[32350]: time="2024-05-07T12:06:01+08:00" level=debug msg="completed challenge"
May 07 12:06:01 minidsp-shd volumio[694]: info: Initializing connection to go-librespot Websocket
May 07 12:06:01 minidsp-shd go-librespot[32350]: time="2024-05-07T12:06:01+08:00" level=debug msg="new websocket client"
May 07 12:06:01 minidsp-shd volumio[694]: info: Connection to go-librespot Websocket established
May 07 12:06:01 minidsp-shd go-librespot[32350]: time="2024-05-07T12:06:01+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
May 07 12:06:01 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
May 07 12:06:01 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
May 07 12:06:01 minidsp-shd volumio[694]: info: Connection to go-librespot Websocket closed
May 07 12:06:04 minidsp-shd nmbd[632]: [2024/05/07 12:06:04.015406, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response)
May 07 12:06:04 minidsp-shd nmbd[632]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.1.160 for name WORKGROUP<1d>.
May 07 12:06:04 minidsp-shd nmbd[632]: This response was from IP 192.168.1.1, reporting an IP address of 192.168.1.1.
May 07 12:06:04 minidsp-shd volumio[694]: info: Getting Spotify volume
May 07 12:06:04 minidsp-shd volumio[694]: (node:694) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
May 07 12:06:04 minidsp-shd volumio[694]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16)
May 07 12:06:04 minidsp-shd volumio[694]: (node:694) 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: 1073)
May 07 12:06:04 minidsp-shd volumio[694]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9
May 07 12:06:04 minidsp-shd volumio[694]: info: CoreCommandRouter::volumioGetState
May 07 12:06:04 minidsp-shd volumio[694]: info: CorePlayQueue::getTrack 0
May 07 12:06:04 minidsp-shd volumio[694]: info: Initializing connection to go-librespot Websocket
May 07 12:06:04 minidsp-shd volumio[694]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90
May 07 12:06:04 minidsp-shd volumio[694]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
May 07 12:06:04 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
May 07 12:06:04 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2163.
May 07 12:06:04 minidsp-shd systemd[1]: Stopped go-librespot Daemon.
May 07 12:06:04 minidsp-shd systemd[1]: Started go-librespot Daemon.
May 07 12:06:04 minidsp-shd go-librespot[32402]: Librespot-go daemon starting...
May 07 12:06:04 minidsp-shd go-librespot[32402]: time="2024-05-07T12:06:04+08:00" level=info msg="generated new device id: cac137f3cca1edfb6da89eb3607634eebe8a9de4"
May 07 12:06:04 minidsp-shd go-librespot[32402]: time="2024-05-07T12:06:04+08:00" level=debug msg="stored credentials found for 15fjn881bvuykffqz6883c23j"
May 07 12:06:05 minidsp-shd go-librespot[32402]: time="2024-05-07T12:06:05+08:00" level=debug msg="obtained new client token: AACsiwi1u4fyRp2ibukeUda/dRY42jNBWRnSPeiKPBZ5IPvkGf2iGwA4nGtLe7aYrVM+CRnb9QlDMmkLPfOtghDUdZblbAY5qome8I+F5pODEnWqfpvgnO/nhiWhuPOpoXSyWATFAJ4dH2Hb1PrVfygJewOEt6C5EIuV/8Wtkhgxy9jaISQyjogodrGyxt4RU2GpqJAcQKFFwxInrbUvL11KBQdguuWYMLT9FGO1mJVZKtZPTpokH95m6BM9ePJv"
May 07 12:06:06 minidsp-shd go-librespot[32402]: time="2024-05-07T12:06:06+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
May 07 12:06:06 minidsp-shd go-librespot[32402]: time="2024-05-07T12:06:06+08:00" level=debug msg="completed keyexchange"
May 07 12:06:07 minidsp-shd volumio[694]: info: Initializing connection to go-librespot Websocket
May 07 12:06:07 minidsp-shd go-librespot[32402]: time="2024-05-07T12:06:07+08:00" level=debug msg="new websocket client"
May 07 12:06:07 minidsp-shd volumio[694]: info: Connection to go-librespot Websocket established
May 07 12:06:07 minidsp-shd go-librespot[32402]: time="2024-05-07T12:06:07+08:00" level=debug msg="completed challenge"
May 07 12:06:07 minidsp-shd go-librespot[32402]: time="2024-05-07T12:06:07+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
May 07 12:06:07 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
May 07 12:06:07 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
May 07 12:06:07 minidsp-shd volumio[694]: info: Connection to go-librespot Websocket closed
May 07 12:06:10 minidsp-shd volumio[694]: info: Getting Spotify volume
May 07 12:06:10 minidsp-shd volumio[694]: (node:694) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
May 07 12:06:10 minidsp-shd volumio[694]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16)
May 07 12:06:10 minidsp-shd volumio[694]: (node:694) 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: 1074)
May 07 12:06:10 minidsp-shd volumio[694]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9
May 07 12:06:10 minidsp-shd volumio[694]: info: CoreCommandRouter::volumioGetState
May 07 12:06:10 minidsp-shd volumio[694]: info: CorePlayQueue::getTrack 0
May 07 12:06:10 minidsp-shd volumio[694]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90
May 07 12:06:10 minidsp-shd volumio[694]: info: Initializing connection to go-librespot Websocket
May 07 12:06:10 minidsp-shd volumio[694]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
May 07 12:06:10 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
May 07 12:06:10 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2164.
May 07 12:06:10 minidsp-shd systemd[1]: Stopped go-librespot Daemon.
May 07 12:06:10 minidsp-shd systemd[1]: Started go-librespot Daemon.
May 07 12:06:10 minidsp-shd go-librespot[32411]: Librespot-go daemon starting...
May 07 12:06:10 minidsp-shd go-librespot[32411]: time="2024-05-07T12:06:10+08:00" level=info msg="generated new device id: 3c1d0a3a9d6a554c89569319883d7894e68adc2d"
May 07 12:06:10 minidsp-shd go-librespot[32411]: time="2024-05-07T12:06:10+08:00" level=debug msg="stored credentials found for 15fjn881bvuykffqz6883c23j"
May 07 12:06:11 minidsp-shd go-librespot[32411]: time="2024-05-07T12:06:11+08:00" level=debug msg="obtained new client token: AAC27lQUqvzkRNeBL6oXbWusoojk7/fxZD3/CgSW+9ZHWYXl28jsuivO5dVzDorasFAGhZLip5G5JsN2Xm9GKHEJ9NnlcOVktID4/Wort38rBBreJ4RGIIjSchwJjfpQtRYSqyPr350fzWCGeN4NF37ayBP24FntbpOuSRY7Pkx8kDlwZJU31h0ZF2ZjvqgMp/WNmX0oFB1is8iipx4b+Pqx/FRefPsCwoIJDBdevebpJiG03iihmGqbNsmCMAWe"
May 07 12:06:12 minidsp-shd go-librespot[32411]: time="2024-05-07T12:06:12+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
May 07 12:06:12 minidsp-shd go-librespot[32411]: time="2024-05-07T12:06:12+08:00" level=debug msg="completed keyexchange"
May 07 12:06:13 minidsp-shd go-librespot[32411]: time="2024-05-07T12:06:13+08:00" level=debug msg="completed challenge"
May 07 12:06:13 minidsp-shd volumio[694]: info: Initializing connection to go-librespot Websocket
May 07 12:06:13 minidsp-shd go-librespot[32411]: time="2024-05-07T12:06:13+08:00" level=debug msg="new websocket client"
May 07 12:06:13 minidsp-shd volumio[694]: info: Connection to go-librespot Websocket established
May 07 12:06:13 minidsp-shd go-librespot[32411]: time="2024-05-07T12:06:13+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
May 07 12:06:13 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
May 07 12:06:13 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
May 07 12:06:13 minidsp-shd volumio[694]: info: Connection to go-librespot Websocket closed
May 07 12:06:16 minidsp-shd volumio[694]: info: Getting Spotify volume
May 07 12:06:16 minidsp-shd volumio[694]: (node:694) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
May 07 12:06:16 minidsp-shd volumio[694]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16)
May 07 12:06:16 minidsp-shd volumio[694]: (node:694) 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: 1075)
May 07 12:06:16 minidsp-shd volumio[694]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9
May 07 12:06:16 minidsp-shd volumio[694]: info: Initializing connection to go-librespot Websocket
May 07 12:06:16 minidsp-shd volumio[694]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
May 07 12:06:16 minidsp-shd volumio[694]: info: CoreCommandRouter::volumioGetState
May 07 12:06:16 minidsp-shd volumio[694]: info: CorePlayQueue::getTrack 0
May 07 12:06:16 minidsp-shd volumio[694]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90
May 07 12:06:16 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
May 07 12:06:16 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2165.
May 07 12:06:16 minidsp-shd systemd[1]: Stopped go-librespot Daemon.
May 07 12:06:16 minidsp-shd systemd[1]: Started go-librespot Daemon.
May 07 12:06:16 minidsp-shd go-librespot[32419]: Librespot-go daemon starting...
May 07 12:06:16 minidsp-shd go-librespot[32419]: time="2024-05-07T12:06:16+08:00" level=info msg="generated new device id: cda36903cb85f9f595e12bcf6274235606102fea"
May 07 12:06:16 minidsp-shd go-librespot[32419]: time="2024-05-07T12:06:16+08:00" level=debug msg="stored credentials found for 15fjn881bvuykffqz6883c23j"
May 07 12:06:17 minidsp-shd go-librespot[32419]: time="2024-05-07T12:06:17+08:00" level=debug msg="obtained new client token: AAD0Z3WhV+PRU9BR8syYsWRI8dkXhF6oTWqXHMMw4rUUt+kx64WUJoN38+LoJSWojhp5PEcMKTZtkD/xGNWFMuEoJfrPkwO+e7Vc3sYk8c9qaonSz5XJkXU6RjSEuiRFAEojtimUbMgyU6NhWCOP1YahiLmcsaWboHDFZOI/yrVg8sYcb2EJ6GXQjSvIrAbtptY8g0NgfJUjwMX2ZX0SkUqWl1pIBY+e2RiXWSSzymUZ3exBMSlgz1YionNE6cZU"
May 07 12:06:18 minidsp-shd go-librespot[32419]: time="2024-05-07T12:06:18+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
May 07 12:06:19 minidsp-shd go-librespot[32419]: time="2024-05-07T12:06:19+08:00" level=debug msg="completed keyexchange"
May 07 12:06:19 minidsp-shd volumio[694]: info: Initializing connection to go-librespot Websocket
May 07 12:06:19 minidsp-shd go-librespot[32419]: time="2024-05-07T12:06:19+08:00" level=debug msg="new websocket client"
May 07 12:06:19 minidsp-shd volumio[694]: info: Connection to go-librespot Websocket established
May 07 12:06:19 minidsp-shd go-librespot[32419]: time="2024-05-07T12:06:19+08:00" level=debug msg="completed challenge"
May 07 12:06:19 minidsp-shd go-librespot[32419]: time="2024-05-07T12:06:19+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
May 07 12:06:19 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
May 07 12:06:19 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
May 07 12:06:19 minidsp-shd volumio[694]: info: Connection to go-librespot Websocket closed
May 07 12:06:22 minidsp-shd volumio[694]: info: Getting Spotify volume
May 07 12:06:22 minidsp-shd volumio[694]: (node:694) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
May 07 12:06:22 minidsp-shd volumio[694]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16)
May 07 12:06:22 minidsp-shd volumio[694]: (node:694) 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: 1076)
May 07 12:06:22 minidsp-shd volumio[694]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9
May 07 12:06:22 minidsp-shd volumio[694]: info: CoreCommandRouter::volumioGetState
May 07 12:06:22 minidsp-shd volumio[694]: info: CorePlayQueue::getTrack 0
May 07 12:06:22 minidsp-shd volumio[694]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90
May 07 12:06:22 minidsp-shd volumio[694]: info: Initializing connection to go-librespot Websocket
May 07 12:06:22 minidsp-shd volumio[694]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
May 07 12:06:22 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
May 07 12:06:22 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2166.
May 07 12:06:22 minidsp-shd systemd[1]: Stopped go-librespot Daemon.
May 07 12:06:22 minidsp-shd systemd[1]: Started go-librespot Daemon.
May 07 12:06:22 minidsp-shd go-librespot[32428]: Librespot-go daemon starting...
May 07 12:06:22 minidsp-shd go-librespot[32428]: time="2024-05-07T12:06:22+08:00" level=info msg="generated new device id: dfe7a102ba6bb022afa28a09e901bdd1f6fa4cb9"
May 07 12:06:22 minidsp-shd go-librespot[32428]: time="2024-05-07T12:06:22+08:00" level=debug msg="stored credentials found for 15fjn881bvuykffqz6883c23j"
May 07 12:06:24 minidsp-shd go-librespot[32428]: time="2024-05-07T12:06:24+08:00" level=debug msg="obtained new client token: AAB8XSBkBXQmMrgJlOZxLVOvWE9pAkPdjzJJLYJlglDrdThsv8v5kLfK+e95lUp6O3ZsXlH0LmmEMvBHRpoymaxulyXQ0qPVcDyBK2ghFkA5Di7Bmi74I0WshGYOfiv1WBGab7E/FS8tnHeLzuY6+h/KlbAKtcW9b6NNByriDGbW+TvQjfIs9gEwJ2QjaMz+/lUOv12Y5z5qpyytFrikeGep5OlXoFR4UKJNFHoPJm2PqYXF6aKIYENYh2W+kSc2"
May 07 12:06:24 minidsp-shd go-librespot[32428]: time="2024-05-07T12:06:24+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
May 07 12:06:25 minidsp-shd go-librespot[32428]: time="2024-05-07T12:06:25+08:00" level=debug msg="completed keyexchange"
May 07 12:06:25 minidsp-shd volumio[694]: info: Initializing connection to go-librespot Websocket
May 07 12:06:25 minidsp-shd go-librespot[32428]: time="2024-05-07T12:06:25+08:00" level=debug msg="new websocket client"
May 07 12:06:25 minidsp-shd volumio[694]: info: Connection to go-librespot Websocket established
May 07 12:06:25 minidsp-shd go-librespot[32428]: time="2024-05-07T12:06:25+08:00" level=debug msg="completed challenge"
May 07 12:06:25 minidsp-shd go-librespot[32428]: time="2024-05-07T12:06:25+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
May 07 12:06:25 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
May 07 12:06:25 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
May 07 12:06:25 minidsp-shd volumio[694]: info: Connection to go-librespot Websocket closed
May 07 12:06:28 minidsp-shd volumio[694]: info: Getting Spotify volume
May 07 12:06:28 minidsp-shd volumio[694]: (node:694) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
May 07 12:06:28 minidsp-shd volumio[694]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16)
May 07 12:06:28 minidsp-shd volumio[694]: (node:694) 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: 1077)
May 07 12:06:28 minidsp-shd volumio[694]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9
May 07 12:06:28 minidsp-shd volumio[694]: info: CoreCommandRouter::volumioGetState
May 07 12:06:28 minidsp-shd volumio[694]: info: CorePlayQueue::getTrack 0
May 07 12:06:28 minidsp-shd volumio[694]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90
May 07 12:06:28 minidsp-shd volumio[694]: info: Initializing connection to go-librespot Websocket
May 07 12:06:28 minidsp-shd volumio[694]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
May 07 12:06:28 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
May 07 12:06:28 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2167.
May 07 12:06:28 minidsp-shd systemd[1]: Stopped go-librespot Daemon.
May 07 12:06:28 minidsp-shd systemd[1]: Started go-librespot Daemon.
May 07 12:06:28 minidsp-shd go-librespot[32438]: Librespot-go daemon starting...
May 07 12:06:28 minidsp-shd go-librespot[32438]: time="2024-05-07T12:06:28+08:00" level=info msg="generated new device id: 423bdf8bd8f5fe6c81b6429268f8752346fc2051"
May 07 12:06:28 minidsp-shd go-librespot[32438]: time="2024-05-07T12:06:28+08:00" level=debug msg="stored credentials found for 15fjn881bvuykffqz6883c23j"
May 07 12:06:30 minidsp-shd go-librespot[32438]: time="2024-05-07T12:06:30+08:00" level=debug msg="obtained new client token: AADyHvR3QFsAj/pgARHBKRCPMMPfd9WGH8CaUFMY6hPw9tyO6Fd7nqxWTMCUBkf7fm4dpbaSP6O5gtrNYE5tZCwvKdC95e9StAhRkqGaVQwv7AdVXQwaYeXuOwIsg68STwHJb/is4usaweOZUoyTk2os1Z8fVK6puuKv6RiRL6MoXJun5NGbMjJBzgjrvn7liXYA2kF7Iq3IBTx+/ozbyasrt97uaV/nJi0dH+QnewOZY6/mL1RWt9szqIxnLOiB"
May 07 12:06:31 minidsp-shd go-librespot[32438]: time="2024-05-07T12:06:31+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
May 07 12:06:31 minidsp-shd volumio[694]: info: Initializing connection to go-librespot Websocket
May 07 12:06:31 minidsp-shd go-librespot[32438]: time="2024-05-07T12:06:31+08:00" level=debug msg="new websocket client"
May 07 12:06:31 minidsp-shd volumio[694]: info: Connection to go-librespot Websocket established
May 07 12:06:31 minidsp-shd go-librespot[32438]: time="2024-05-07T12:06:31+08:00" level=debug msg="completed keyexchange"
May 07 12:06:32 minidsp-shd go-librespot[32438]: time="2024-05-07T12:06:32+08:00" level=debug msg="completed challenge"
May 07 12:06:32 minidsp-shd go-librespot[32438]: time="2024-05-07T12:06:32+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
May 07 12:06:32 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
May 07 12:06:32 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
May 07 12:06:32 minidsp-shd volumio[694]: info: Connection to go-librespot Websocket closed
May 07 12:06:34 minidsp-shd volumio[694]: info: Getting Spotify volume
May 07 12:06:34 minidsp-shd volumio[694]: (node:694) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
May 07 12:06:34 minidsp-shd volumio[694]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16)
May 07 12:06:34 minidsp-shd volumio[694]: (node:694) 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: 1078)
May 07 12:06:34 minidsp-shd volumio[694]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9
May 07 12:06:34 minidsp-shd volumio[694]: info: CoreCommandRouter::volumioGetState
May 07 12:06:34 minidsp-shd volumio[694]: info: CorePlayQueue::getTrack 0
May 07 12:06:34 minidsp-shd volumio[694]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90
May 07 12:06:35 minidsp-shd volumio[694]: info: Initializing connection to go-librespot Websocket
May 07 12:06:35 minidsp-shd volumio[694]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
May 07 12:06:35 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
May 07 12:06:35 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2168.
May 07 12:06:35 minidsp-shd systemd[1]: Stopped go-librespot Daemon.
May 07 12:06:35 minidsp-shd systemd[1]: Started go-librespot Daemon.
May 07 12:06:35 minidsp-shd go-librespot[32446]: Librespot-go daemon starting...
May 07 12:06:35 minidsp-shd go-librespot[32446]: time="2024-05-07T12:06:35+08:00" level=info msg="generated new device id: eeceaefef11256de6e0a2a63702b6a660dad5f06"
May 07 12:06:35 minidsp-shd go-librespot[32446]: time="2024-05-07T12:06:35+08:00" level=debug msg="stored credentials found for 15fjn881bvuykffqz6883c23j"
May 07 12:06:37 minidsp-shd go-librespot[32446]: time="2024-05-07T12:06:37+08:00" level=debug msg="obtained new client token: AABg6z47WCtct0kPAF5rJq7wMeZS+9vU4dD5gQQlepwwUUF6MOLE9dizB/ZANevE68zUapxHh+82o91ibzD4h3On1mqIDA7I2CuqoSGBC2v0LK++ieNxgNcjq7JjajXP1tM1CxJRfm+mrvKs6+hfHCcjCufIxmjdBgoIexPj/KWP5fUcKxCOk1ZRpTysQh0lodta/0eqgByJfSk1+/sNkvewVM0cmRJ7EkJpyk85CjvW1rFoFXHuP5ipTFTzbNGO"
May 07 12:06:38 minidsp-shd volumio[694]: info: Initializing connection to go-librespot Websocket
May 07 12:06:38 minidsp-shd go-librespot[32446]: time="2024-05-07T12:06:38+08:00" level=debug msg="new websocket client"
May 07 12:06:38 minidsp-shd volumio[694]: info: Connection to go-librespot Websocket established
May 07 12:06:39 minidsp-shd go-librespot[32446]: time="2024-05-07T12:06:39+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
May 07 12:06:39 minidsp-shd go-librespot[32446]: time="2024-05-07T12:06:39+08:00" level=debug msg="completed keyexchange"
May 07 12:06:40 minidsp-shd go-librespot[32446]: time="2024-05-07T12:06:40+08:00" level=debug msg="completed challenge"
May 07 12:06:40 minidsp-shd go-librespot[32446]: time="2024-05-07T12:06:40+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
May 07 12:06:40 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
May 07 12:06:40 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
May 07 12:06:40 minidsp-shd volumio[694]: info: Connection to go-librespot Websocket closed
May 07 12:06:41 minidsp-shd volumio[694]: info: Getting Spotify volume
May 07 12:06:41 minidsp-shd volumio[694]: (node:694) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
May 07 12:06:41 minidsp-shd volumio[694]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16)
May 07 12:06:41 minidsp-shd volumio[694]: (node:694) 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: 1079)
May 07 12:06:41 minidsp-shd volumio[694]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9
May 07 12:06:41 minidsp-shd volumio[694]: info: CoreCommandRouter::volumioGetState
May 07 12:06:41 minidsp-shd volumio[694]: info: CorePlayQueue::getTrack 0
May 07 12:06:41 minidsp-shd volumio[694]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90
May 07 12:06:43 minidsp-shd volumio[694]: info: Initializing connection to go-librespot Websocket
May 07 12:06:43 minidsp-shd volumio[694]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
May 07 12:06:43 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
May 07 12:06:43 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2169.
May 07 12:06:43 minidsp-shd systemd[1]: Stopped go-librespot Daemon.
May 07 12:06:43 minidsp-shd systemd[1]: Started go-librespot Daemon.
May 07 12:06:43 minidsp-shd go-librespot[32455]: Librespot-go daemon starting...
May 07 12:06:43 minidsp-shd go-librespot[32455]: time="2024-05-07T12:06:43+08:00" level=info msg="generated new device id: 7a8434a7cc2426f747a95adcec2b2bb49b789da9"
May 07 12:06:43 minidsp-shd go-librespot[32455]: time="2024-05-07T12:06:43+08:00" level=debug msg="stored credentials found for 15fjn881bvuykffqz6883c23j"
May 07 12:06:44 minidsp-shd go-librespot[32455]: time="2024-05-07T12:06:44+08:00" level=debug msg="obtained new client token: AAD1jhray2o1I96OCp7mHVpyVdN75Ql0POY9MYJInLdMowAG3H9Kj35ZicPHxEw+094YfOM+LFjCF/ABvGwfJj65v92fEzMU36kFHM84JTjKvpUVzBcDYJsbyjUMudnQrW0jUvKCkyTvdeITTyGgDEMGASOg4ZvJLZWjK8OJ7WxaRN5yBUp5Zrh5CmDoN+NAdlxkPQRCFucS1ycxSzirx3cXp00S1VTgZTfzt3Fwl2QbfGuKk6OklKETJgUEuzED"
May 07 12:06:45 minidsp-shd volumio[694]: info: CoreCommandRouter::servicePushState
May 07 12:06:45 minidsp-shd volumio[694]: info: CorePlayQueue::getTrack 0
May 07 12:06:45 minidsp-shd volumio[694]: verbose: STATE SERVICE {"status":"pause","service":"raat","title":"Faure, Gabriel - Impromptu, Op.86","artist":"De Falla,Albeniz, Guridi, Mozart, Beethoven, Britten, Faur? Piern? Salzedo.... / Marisa Robles / 加布里埃尔·福莱","album":"De Falla,Albeniz, Guridi, Mozart, Beethoven, Britten, Faur? Piern? Salzedo. B...","albumart":"/albumart?web=100/extralarge&path=/tmp/raat/albumart/fcb5d1f90011f6f216742238c3b1e7c2.jpg","uri":"","trackType":"","seek":20000,"duration":541,"samplerate":"","bitdepth":"","channels":2,"disableUiControls":false,"push_time":1715054611083}
May 07 12:06:45 minidsp-shd volumio[694]: verbose: CURRENT POSITION 0
May 07 12:06:45 minidsp-shd volumio[694]: info: CoreStateMachine::syncState stateService pause
May 07 12:06:45 minidsp-shd volumio[694]: info: CoreStateMachine::syncState currentStatus stop
May 07 12:06:45 minidsp-shd volumio[694]: info: CoreStateMachine::pushState
May 07 12:06:45 minidsp-shd volumio[694]: info: CorePlayQueue::getTrack 0
May 07 12:06:45 minidsp-shd volumio[694]: info: CoreCommandRouter::volumioPushState
May 07 12:06:45 minidsp-shd volumio[694]: info: MRS: Pushing multiroomSync output update for this device
May 07 12:06:45 minidsp-shd volumio[694]: info: MRS: Pushing multiroomSync output
May 07 12:06:45 minidsp-shd volumio[694]: info: Updating RAAT Signal Path
May 07 12:06:45 minidsp-shd volumio[694]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90
May 07 12:06:45 minidsp-shd go-librespot[32455]: time="2024-05-07T12:06:45+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
May 07 12:06:45 minidsp-shd go-librespot[32455]: time="2024-05-07T12:06:45+08:00" level=debug msg="completed keyexchange"
May 07 12:06:46 minidsp-shd volumio[694]: info: Initializing connection to go-librespot Websocket
May 07 12:06:46 minidsp-shd go-librespot[32455]: time="2024-05-07T12:06:46+08:00" level=debug msg="new websocket client"
May 07 12:06:46 minidsp-shd volumio[694]: info: Connection to go-librespot Websocket established
May 07 12:06:46 minidsp-shd go-librespot[32455]: time="2024-05-07T12:06:46+08:00" level=debug msg="completed challenge"
May 07 12:06:46 minidsp-shd go-librespot[32455]: time="2024-05-07T12:06:46+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
May 07 12:06:46 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
May 07 12:06:46 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
May 07 12:06:46 minidsp-shd volumio[694]: info: Connection to go-librespot Websocket closed
May 07 12:06:46 minidsp-shd volumio[694]: info: CoreCommandRouter::servicePushState
May 07 12:06:46 minidsp-shd volumio[694]: info: CorePlayQueue::getTrack 0
May 07 12:06:46 minidsp-shd volumio[694]: verbose: STATE SERVICE {"status":"pause","service":"raat","title":"Faure, Gabriel - Impromptu, Op.86","artist":"De Falla,Albeniz, Guridi, Mozart, Beethoven, Britten, Faur? Piern? Salzedo.... / Marisa Robles / 加布里埃尔·福莱","album":"De Falla,Albeniz, Guridi, Mozart, Beethoven, Britten, Faur? Piern? Salzedo. B...","albumart":"/albumart?web=100/extralarge&path=/tmp/raat/albumart/fcb5d1f90011f6f216742238c3b1e7c2.jpg","uri":"","trackType":"","seek":20000,"duration":541,"samplerate":"","bitdepth":"","channels":2,"disableUiControls":false,"push_time":1715054805167}
May 07 12:06:46 minidsp-shd volumio[694]: verbose: CURRENT POSITION 0
May 07 12:06:46 minidsp-shd volumio[694]: info: CoreStateMachine::syncState stateService pause
May 07 12:06:46 minidsp-shd volumio[694]: info: CoreStateMachine::syncState currentStatus stop
May 07 12:06:46 minidsp-shd volumio[694]: info: CoreStateMachine::pushState
May 07 12:06:46 minidsp-shd volumio[694]: info: CorePlayQueue::getTrack 0
May 07 12:06:46 minidsp-shd volumio[694]: info: CoreCommandRouter::volumioPushState
May 07 12:06:46 minidsp-shd volumio[694]: info: MRS: Pushing multiroomSync output update for this device
May 07 12:06:46 minidsp-shd volumio[694]: info: MRS: Pushing multiroomSync output
May 07 12:06:46 minidsp-shd volumio[694]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90
May 07 12:06:49 minidsp-shd volumio[694]: info: Getting Spotify volume
May 07 12:06:49 minidsp-shd volumio[694]: (node:694) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
May 07 12:06:49 minidsp-shd volumio[694]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16)
May 07 12:06:49 minidsp-shd volumio[694]: (node:694) 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: 1080)
May 07 12:06:49 minidsp-shd volumio[694]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9
May 07 12:06:49 minidsp-shd volumio[694]: info: CoreCommandRouter::volumioGetState
May 07 12:06:49 minidsp-shd volumio[694]: info: CorePlayQueue::getTrack 0
May 07 12:06:49 minidsp-shd volumio[694]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90
May 07 12:06:49 minidsp-shd volumio[694]: info: Initializing connection to go-librespot Websocket
May 07 12:06:49 minidsp-shd volumio[694]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
May 07 12:06:49 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
May 07 12:06:49 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2170.
May 07 12:06:49 minidsp-shd systemd[1]: Stopped go-librespot Daemon.
May 07 12:06:49 minidsp-shd systemd[1]: Started go-librespot Daemon.
May 07 12:06:49 minidsp-shd go-librespot[32464]: Librespot-go daemon starting...
May 07 12:06:49 minidsp-shd go-librespot[32464]: time="2024-05-07T12:06:49+08:00" level=info msg="generated new device id: 6c7ffaa0539ba34ad30197ebfd53abc514060452"
May 07 12:06:49 minidsp-shd go-librespot[32464]: time="2024-05-07T12:06:49+08:00" level=debug msg="stored credentials found for 15fjn881bvuykffqz6883c23j"
May 07 12:06:50 minidsp-shd go-librespot[32464]: time="2024-05-07T12:06:50+08:00" level=debug msg="obtained new client token: AABhzmRhDHVzarKwXfntnZzDBz9YL30L2wpz21LU1HuYj4hV5w4LuS+rSdnzPafwyUn7weHuzC+wnnfyADHcQzipspso+OObvKE1eEgRILARv62zv8lko2NMf4NQY9JNrXjcNhiiLRFW/dMVasdYCH8ivxtJNvGrvjNSJN+jY5Lg8ACOZ/eImGyLfK+CYqLaPgsXtWENnoPZq8OHG6cyDC9evZ0s2oot00ub2/PNTJ7SlCYkUwm3gCgV+w8pq5fI"
May 07 12:06:51 minidsp-shd go-librespot[32464]: time="2024-05-07T12:06:51+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
May 07 12:06:52 minidsp-shd go-librespot[32464]: time="2024-05-07T12:06:52+08:00" level=debug msg="completed keyexchange"
May 07 12:06:52 minidsp-shd go-librespot[32464]: time="2024-05-07T12:06:52+08:00" level=debug msg="completed challenge"
May 07 12:06:52 minidsp-shd volumio[694]: info: Initializing connection to go-librespot Websocket
May 07 12:06:52 minidsp-shd go-librespot[32464]: time="2024-05-07T12:06:52+08:00" level=debug msg="new websocket client"
May 07 12:06:52 minidsp-shd volumio[694]: info: Connection to go-librespot Websocket established
May 07 12:06:52 minidsp-shd go-librespot[32464]: time="2024-05-07T12:06:52+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
May 07 12:06:52 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
May 07 12:06:52 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
May 07 12:06:52 minidsp-shd volumio[694]: info: Connection to go-librespot Websocket closed
May 07 12:06:55 minidsp-shd volumio[694]: info: Getting Spotify volume
May 07 12:06:55 minidsp-shd volumio[694]: (node:694) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
May 07 12:06:55 minidsp-shd volumio[694]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16)
May 07 12:06:55 minidsp-shd volumio[694]: (node:694) 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: 1081)
May 07 12:06:55 minidsp-shd volumio[694]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9
May 07 12:06:55 minidsp-shd volumio[694]: info: Initializing connection to go-librespot Websocket
May 07 12:06:55 minidsp-shd volumio[694]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
May 07 12:06:55 minidsp-shd volumio[694]: info: CoreCommandRouter::volumioGetState
May 07 12:06:55 minidsp-shd volumio[694]: info: CorePlayQueue::getTrack 0
May 07 12:06:55 minidsp-shd volumio[694]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90
May 07 12:06:55 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
May 07 12:06:55 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2171.
May 07 12:06:55 minidsp-shd systemd[1]: Stopped go-librespot Daemon.
May 07 12:06:55 minidsp-shd systemd[1]: Started go-librespot Daemon.
May 07 12:06:55 minidsp-shd go-librespot[32472]: Librespot-go daemon starting...
May 07 12:06:55 minidsp-shd go-librespot[32472]: time="2024-05-07T12:06:55+08:00" level=info msg="generated new device id: 64e7461c6a084ed5feab3014c584e0a8dc8eae11"
May 07 12:06:55 minidsp-shd go-librespot[32472]: time="2024-05-07T12:06:55+08:00" level=debug msg="stored credentials found for 15fjn881bvuykffqz6883c23j"
May 07 12:06:57 minidsp-shd go-librespot[32472]: time="2024-05-07T12:06:57+08:00" level=debug msg="obtained new client token: AAAzTehURruqT7DhAGQxqgwOw6kW5MLZYu/MMmR31jhFzT2c7NEwK5SAn3uVH/avKVnfX93t7FoGCus2dCVS8g/89OXhbNrBMszkQF4Lpky2gT7FudJaz42YuurGS1fQvoQQmvGAPvJBLOvJeWjO6G4NfOaSSsZDEJG9nv5uBRhFpLego3DirmSPX3y++KdLKOSS4u4IsyQ4Ee/7zyPAmwNgEPKOPAoMObIGfODliFsPZzj9BX6oY9Hgnq5dGit/"
May 07 12:06:58 minidsp-shd volumio[694]: info: Initializing connection to go-librespot Websocket
May 07 12:06:58 minidsp-shd go-librespot[32472]: time="2024-05-07T12:06:58+08:00" level=debug msg="new websocket client"
May 07 12:06:58 minidsp-shd volumio[694]: info: Connection to go-librespot Websocket established
May 07 12:07:01 minidsp-shd go-librespot[32472]: time="2024-05-07T12:07:01+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
May 07 12:07:01 minidsp-shd go-librespot[32472]: time="2024-05-07T12:07:01+08:00" level=debug msg="completed keyexchange"
May 07 12:07:01 minidsp-shd volumio[694]: info: Getting Spotify volume
May 07 12:07:01 minidsp-shd volumio[694]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9
May 07 12:07:01 minidsp-shd volumio[694]: info: CoreCommandRouter::volumioGetState
May 07 12:07:01 minidsp-shd volumio[694]: info: CorePlayQueue::getTrack 0
May 07 12:07:01 minidsp-shd volumio[694]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90
May 07 12:07:01 minidsp-shd go-librespot[32472]: time="2024-05-07T12:07:01+08:00" level=debug msg="completed challenge"
May 07 12:07:01 minidsp-shd go-librespot[32472]: time="2024-05-07T12:07:01+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
May 07 12:07:01 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
May 07 12:07:01 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
May 07 12:07:01 minidsp-shd volumio[694]: (node:694) UnhandledPromiseRejectionWarning: Error: socket hang up
May 07 12:07:01 minidsp-shd volumio[694]: at connResetException (internal/errors.js:639:14)
May 07 12:07:01 minidsp-shd volumio[694]: at Socket.socketOnEnd (_http_client.js:499:23)
May 07 12:07:01 minidsp-shd volumio[694]: at Socket.emit (events.js:412:35)
May 07 12:07:01 minidsp-shd volumio[694]: at endReadableNT (internal/streams/readable.js:1333:12)
May 07 12:07:01 minidsp-shd volumio[694]: at processTicksAndRejections (internal/process/task_queues.js:82:21)
May 07 12:07:01 minidsp-shd volumio[694]: (node:694) 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: 1082)
May 07 12:07:01 minidsp-shd volumio[694]: info: Connection to go-librespot Websocket closed
May 07 12:07:04 minidsp-shd volumio[694]: info: Initializing connection to go-librespot Websocket
May 07 12:07:04 minidsp-shd volumio[694]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
May 07 12:07:05 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
May 07 12:07:05 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2172.
May 07 12:07:05 minidsp-shd systemd[1]: Stopped go-librespot Daemon.
May 07 12:07:05 minidsp-shd systemd[1]: Started go-librespot Daemon.
May 07 12:07:05 minidsp-shd go-librespot[32525]: Librespot-go daemon starting...
May 07 12:07:05 minidsp-shd go-librespot[32525]: time="2024-05-07T12:07:05+08:00" level=info msg="generated new device id: f490ac56dc256e959e41a1c54635143187814822"
May 07 12:07:05 minidsp-shd go-librespot[32525]: time="2024-05-07T12:07:05+08:00" level=debug msg="stored credentials found for 15fjn881bvuykffqz6883c23j"
May 07 12:07:06 minidsp-shd go-librespot[32525]: time="2024-05-07T12:07:06+08:00" level=debug msg="obtained new client token: AAAci3tAh11Ofhy/p3gvV9GZYUJOK5Oguc7zlNn3Z4pdCq71oSOS2MyFpgBkrRZOrta75ToYKVcPaV88zHKXZG3pa5jLrVud9T7jBVr9HJ7ekJpUmzOwPYnCG/J3S9tfs3S//1tZniOuIY/mBYnIx074QJC1aM5k6TBLC5bZFVjL1kF5zyyPdff0U4/E5vR2WaHkYvMEKbll8QDYlKizZktxcIZVPXEaVWbWfPSlcGtSg//JiyZoWmPxaCioOA=="
May 07 12:07:07 minidsp-shd go-librespot[32525]: time="2024-05-07T12:07:07+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
May 07 12:07:07 minidsp-shd go-librespot[32525]: time="2024-05-07T12:07:07+08:00" level=debug msg="completed keyexchange"
May 07 12:07:07 minidsp-shd volumio[694]: info: Initializing connection to go-librespot Websocket
May 07 12:07:07 minidsp-shd go-librespot[32525]: time="2024-05-07T12:07:07+08:00" level=debug msg="new websocket client"
May 07 12:07:07 minidsp-shd volumio[694]: info: Connection to go-librespot Websocket established
May 07 12:07:07 minidsp-shd go-librespot[32525]: time="2024-05-07T12:07:07+08:00" level=debug msg="completed challenge"
May 07 12:07:08 minidsp-shd go-librespot[32525]: time="2024-05-07T12:07:08+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
May 07 12:07:08 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
May 07 12:07:08 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
May 07 12:07:08 minidsp-shd volumio[694]: info: Connection to go-librespot Websocket closed
May 07 12:07:10 minidsp-shd volumio[694]: info: Getting Spotify volume
May 07 12:07:10 minidsp-shd volumio[694]: (node:694) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
May 07 12:07:10 minidsp-shd volumio[694]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16)
May 07 12:07:10 minidsp-shd volumio[694]: (node:694) 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: 1083)
May 07 12:07:10 minidsp-shd volumio[694]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9
May 07 12:07:10 minidsp-shd volumio[694]: info: CoreCommandRouter::volumioGetState
May 07 12:07:10 minidsp-shd volumio[694]: info: CorePlayQueue::getTrack 0
May 07 12:07:10 minidsp-shd volumio[694]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90
May 07 12:07:11 minidsp-shd volumio[694]: info: Initializing connection to go-librespot Websocket
May 07 12:07:11 minidsp-shd volumio[694]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
May 07 12:07:11 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
May 07 12:07:11 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2173.
May 07 12:07:11 minidsp-shd systemd[1]: Stopped go-librespot Daemon.
May 07 12:07:11 minidsp-shd systemd[1]: Started go-librespot Daemon.
May 07 12:07:11 minidsp-shd go-librespot[32534]: Librespot-go daemon starting...
May 07 12:07:11 minidsp-shd go-librespot[32534]: time="2024-05-07T12:07:11+08:00" level=info msg="generated new device id: 6a0abc120d424b6c5e1e1a308764304c1e50ee5e"
May 07 12:07:11 minidsp-shd go-librespot[32534]: time="2024-05-07T12:07:11+08:00" level=debug msg="stored credentials found for 15fjn881bvuykffqz6883c23j"
May 07 12:07:12 minidsp-shd go-librespot[32534]: time="2024-05-07T12:07:12+08:00" level=debug msg="obtained new client token: AAA5D49GT0A6ps0RRNihhl7BCbq+eO9z8d0Mg2XVTcr2DzpPtNfr88fk1SBddddcR97vnqqRz8t2khKiQ6MghculT7nNM0Y+kTMl+Nvm8EH8qdHbm3cp3OqOSt38Vds2X027guJAdfh3Et+BHTUQDitNGCbwJVqFirr1f1DIOGVgfEwQAf+h+8biQY29WDXhvLuoJI7T5W96PA4Yy7Ku/zMZ6/05dKejllQHS1f8uLoBxH1fxOHAkW/T+hsBXQ=="
May 07 12:07:13 minidsp-shd go-librespot[32534]: time="2024-05-07T12:07:13+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
May 07 12:07:13 minidsp-shd go-librespot[32534]: time="2024-05-07T12:07:13+08:00" level=debug msg="completed keyexchange"
May 07 12:07:13 minidsp-shd go-librespot[32534]: time="2024-05-07T12:07:13+08:00" level=debug msg="completed challenge"
May 07 12:07:14 minidsp-shd go-librespot[32534]: time="2024-05-07T12:07:14+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
May 07 12:07:14 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
May 07 12:07:14 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
May 07 12:07:14 minidsp-shd volumio[694]: info: Initializing connection to go-librespot Websocket
May 07 12:07:14 minidsp-shd volumio[694]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
May 07 12:07:17 minidsp-shd volumio[694]: info: Initializing connection to go-librespot Websocket
May 07 12:07:17 minidsp-shd volumio[694]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
May 07 12:07:17 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
May 07 12:07:17 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2174.
May 07 12:07:17 minidsp-shd systemd[1]: Stopped go-librespot Daemon.
May 07 12:07:17 minidsp-shd systemd[1]: Started go-librespot Daemon.
May 07 12:07:17 minidsp-shd go-librespot[32542]: Librespot-go daemon starting...
May 07 12:07:17 minidsp-shd go-librespot[32542]: time="2024-05-07T12:07:17+08:00" level=info msg="generated new device id: a55ba0ae81305be5ad8e96b608c57c3eae70dc76"
May 07 12:07:17 minidsp-shd go-librespot[32542]: time="2024-05-07T12:07:17+08:00" level=debug msg="stored credentials found for 15fjn881bvuykffqz6883c23j"
May 07 12:07:18 minidsp-shd go-librespot[32542]: time="2024-05-07T12:07:18+08:00" level=debug msg="obtained new client token: AACP1tLUpipnulRAvlF+UVvDhsHzzTBWNPmUOV3kXN3ZT5TY/dP1IavlKQlF9lVvGzkrr5ONpvo5aE+fC1RgEAbXC5nRifHG+FB0jqE2VRpu/3sVCyS4repz3d3EMj+4UkCN4/zv7e+o5TIOt63uKQnyCBPBr1vt3NiONJABskU7h0tpG45fC3dBMCoSVpCGfEHGfqoB7D/AYcWiWyPOkH9tFB6QutADMTzvpITv3PS8OJljtqcKFTDYJfJfor/Y"
May 07 12:07:19 minidsp-shd go-librespot[32542]: time="2024-05-07T12:07:19+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
May 07 12:07:19 minidsp-shd go-librespot[32542]: time="2024-05-07T12:07:19+08:00" level=debug msg="completed keyexchange"
May 07 12:07:20 minidsp-shd volumio[694]: info: Initializing connection to go-librespot Websocket
May 07 12:07:20 minidsp-shd go-librespot[32542]: time="2024-05-07T12:07:20+08:00" level=debug msg="new websocket client"
May 07 12:07:20 minidsp-shd volumio[694]: info: Connection to go-librespot Websocket established
May 07 12:07:20 minidsp-shd go-librespot[32542]: time="2024-05-07T12:07:20+08:00" level=debug msg="completed challenge"
May 07 12:07:20 minidsp-shd go-librespot[32542]: time="2024-05-07T12:07:20+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
May 07 12:07:20 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
May 07 12:07:20 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
May 07 12:07:20 minidsp-shd volumio[694]: info: Connection to go-librespot Websocket closed
May 07 12:07:22 minidsp-shd volumio[694]: info: CoreCommandRouter::getUIConfigOnPlugin
May 07 12:07:23 minidsp-shd volumio[694]: info: Getting Spotify volume
May 07 12:07:23 minidsp-shd volumio[694]: (node:694) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
May 07 12:07:23 minidsp-shd volumio[694]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16)
May 07 12:07:23 minidsp-shd volumio[694]: (node:694) 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: 1084)
May 07 12:07:23 minidsp-shd volumio[694]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9
May 07 12:07:23 minidsp-shd volumio[694]: info: CoreCommandRouter::volumioGetState
May 07 12:07:23 minidsp-shd volumio[694]: info: CorePlayQueue::getTrack 0
May 07 12:07:23 minidsp-shd volumio[694]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90
May 07 12:07:23 minidsp-shd volumio[694]: info: Initializing connection to go-librespot Websocket
May 07 12:07:23 minidsp-shd volumio[694]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
May 07 12:07:23 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
May 07 12:07:23 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2175.
May 07 12:07:23 minidsp-shd systemd[1]: Stopped go-librespot Daemon.
May 07 12:07:23 minidsp-shd systemd[1]: Started go-librespot Daemon.
May 07 12:07:23 minidsp-shd go-librespot[32550]: Librespot-go daemon starting...
May 07 12:07:23 minidsp-shd go-librespot[32550]: time="2024-05-07T12:07:23+08:00" level=info msg="generated new device id: f2de4954541cc3f56cf3c9dc8633570b16a859de"
May 07 12:07:23 minidsp-shd go-librespot[32550]: time="2024-05-07T12:07:23+08:00" level=debug msg="stored credentials found for 15fjn881bvuykffqz6883c23j"
May 07 12:07:26 minidsp-shd volumio[694]: info: Initializing connection to go-librespot Websocket
May 07 12:07:26 minidsp-shd go-librespot[32550]: time="2024-05-07T12:07:26+08:00" level=debug msg="new websocket client"
May 07 12:07:26 minidsp-shd volumio[694]: info: Connection to go-librespot Websocket established
May 07 12:07:26 minidsp-shd go-librespot[32550]: time="2024-05-07T12:07:26+08:00" level=debug msg="obtained new client token: AACBltoU7UQ6WpFAslW1AEqSO5k/1sMSwTCBsus3HohDbWCjYY7FvQFbuZ/fiDopaXyXicYPt/xz5Bb50pffDzeQRoF1jXPnwBYqKwtiE+4EBsvvdmtPO9N5ewb6yaA+vSQ+m5hsJT6CvTF8SKOa7+kF35AThs1xt64n6p/yhdAGT+rkfYXGiIpMZQE6aEeUGrZ6GIXaWDCdNPddv6szhuJM8UtaBDcMih/B6NDvVBM7Z8EoEAnhX+NNmkEwAq1A"
May 07 12:07:27 minidsp-shd volumio[694]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
May 07 12:07:27 minidsp-shd volumio[694]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
May 07 12:07:27 minidsp-shd go-librespot[32550]: time="2024-05-07T12:07:27+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
May 07 12:07:27 minidsp-shd go-librespot[32550]: time="2024-05-07T12:07:27+08:00" level=debug msg="completed keyexchange"
May 07 12:07:28 minidsp-shd go-librespot[32550]: time="2024-05-07T12:07:28+08:00" level=debug msg="completed challenge"
May 07 12:07:28 minidsp-shd go-librespot[32550]: time="2024-05-07T12:07:28+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
May 07 12:07:28 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
May 07 12:07:28 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
May 07 12:07:28 minidsp-shd volumio[694]: info: Connection to go-librespot Websocket closed
May 07 12:07:29 minidsp-shd volumio[694]: info: Getting Spotify volume
May 07 12:07:29 minidsp-shd volumio[694]: (node:694) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
May 07 12:07:29 minidsp-shd volumio[694]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16)
May 07 12:07:29 minidsp-shd volumio[694]: (node:694) 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: 1085)
May 07 12:07:29 minidsp-shd volumio[694]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9
May 07 12:07:29 minidsp-shd volumio[694]: info: CoreCommandRouter::volumioGetState
May 07 12:07:29 minidsp-shd volumio[694]: info: CorePlayQueue::getTrack 0
May 07 12:07:29 minidsp-shd volumio[694]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90
May 07 12:07:31 minidsp-shd volumio[694]: info: Initializing connection to go-librespot Websocket
May 07 12:07:31 minidsp-shd volumio[694]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
May 07 12:07:31 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
May 07 12:07:31 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2176.
May 07 12:07:31 minidsp-shd systemd[1]: Stopped go-librespot Daemon.
May 07 12:07:31 minidsp-shd systemd[1]: Started go-librespot Daemon.
May 07 12:07:31 minidsp-shd go-librespot[32559]: Librespot-go daemon starting...
May 07 12:07:31 minidsp-shd go-librespot[32559]: time="2024-05-07T12:07:31+08:00" level=info msg="generated new device id: 409e793509e600a47348f070739b2f97578174b0"
May 07 12:07:31 minidsp-shd go-librespot[32559]: time="2024-05-07T12:07:31+08:00" level=debug msg="stored credentials found for 15fjn881bvuykffqz6883c23j"
May 07 12:07:32 minidsp-shd go-librespot[32559]: time="2024-05-07T12:07:32+08:00" level=debug msg="obtained new client token: AABoTPoxZNa204E0uz4rhLYAUL8h7V/6X25aI7alu085A1JMYya5wyd9Yo0kHqbTp20NuzxjTIhKy6C8NfRkUXbk0DfObBg1okEUQGDfQUhLLwgB/lGFSmOl2Kdjl7Sby1ZEN5gq2/Ls0A5vfmpk9YxonYmQ1jDEliY+yBoB9dGwlAtjOgs16a1Y58uSrV5YdfjXK9/X/3eW3L1x4YgU7GZuMwa8oMrbzxYphil8jzG7qMrVKcMMqcels5YEC2IP"
May 07 12:07:33 minidsp-shd go-librespot[32559]: time="2024-05-07T12:07:33+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
May 07 12:07:33 minidsp-shd go-librespot[32559]: time="2024-05-07T12:07:33+08:00" level=debug msg="completed keyexchange"
May 07 12:07:34 minidsp-shd volumio[694]: info: CoreCommandRouter::getUIConfigOnPlugin
May 07 12:07:34 minidsp-shd volumio[694]: info: Initializing connection to go-librespot Websocket
May 07 12:07:34 minidsp-shd go-librespot[32559]: time="2024-05-07T12:07:34+08:00" level=debug msg="completed challenge"
May 07 12:07:34 minidsp-shd go-librespot[32559]: time="2024-05-07T12:07:34+08:00" level=debug msg="new websocket client"
May 07 12:07:34 minidsp-shd volumio[694]: info: Connection to go-librespot Websocket established
May 07 12:07:34 minidsp-shd go-librespot[32559]: time="2024-05-07T12:07:34+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
May 07 12:07:34 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
May 07 12:07:34 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
May 07 12:07:34 minidsp-shd volumio[694]: info: Connection to go-librespot Websocket closed
May 07 12:07:37 minidsp-shd volumio[694]: info: Getting Spotify volume
May 07 12:07:37 minidsp-shd volumio[694]: (node:694) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
May 07 12:07:37 minidsp-shd volumio[694]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16)
May 07 12:07:37 minidsp-shd volumio[694]: (node:694) 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: 1086)
May 07 12:07:37 minidsp-shd volumio[694]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9
May 07 12:07:37 minidsp-shd volumio[694]: info: CoreCommandRouter::volumioGetState
May 07 12:07:37 minidsp-shd volumio[694]: info: CorePlayQueue::getTrack 0
May 07 12:07:37 minidsp-shd volumio[694]: info: Initializing connection to go-librespot Websocket
May 07 12:07:37 minidsp-shd volumio[694]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90
May 07 12:07:37 minidsp-shd volumio[694]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
May 07 12:07:37 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
May 07 12:07:37 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2177.
May 07 12:07:37 minidsp-shd systemd[1]: Stopped go-librespot Daemon.
May 07 12:07:37 minidsp-shd systemd[1]: Started go-librespot Daemon.
May 07 12:07:37 minidsp-shd go-librespot[32569]: Librespot-go daemon starting...
May 07 12:07:37 minidsp-shd go-librespot[32569]: time="2024-05-07T12:07:37+08:00" level=info msg="generated new device id: dc44fea61b1ef5f06478ff5d72d1a62113266eeb"
May 07 12:07:37 minidsp-shd go-librespot[32569]: time="2024-05-07T12:07:37+08:00" level=debug msg="stored credentials found for 15fjn881bvuykffqz6883c23j"
May 07 12:07:38 minidsp-shd go-librespot[32569]: time="2024-05-07T12:07:38+08:00" level=debug msg="obtained new client token: AAD0DWY2np427zOE/V2Jax2zDoqfsrt4Mq2lmlyo/36mCvUERdqg229PKlmssIEMWS81w4D3/YMPuhU9PAtUTpqACE9knW7kleT7Ggh9bcjHuYt9zPIHN0vbbJcXCN8Z4RlwvXgaMPNpuRZS1q+zF4kblmzA3+dSjPnIWJlnKSjnGCfIgnOsKM1iGu2tSm9FfvtrrO7LhE4tsauNNpaFkKzWIpivv+AuOQsgrnJSGvhDZWMLmJ2YrGOPEN1r4zE4"
May 07 12:07:39 minidsp-shd go-librespot[32569]: time="2024-05-07T12:07:39+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
May 07 12:07:40 minidsp-shd go-librespot[32569]: time="2024-05-07T12:07:40+08:00" level=debug msg="completed keyexchange"
May 07 12:07:40 minidsp-shd volumio[694]: info: Initializing connection to go-librespot Websocket
May 07 12:07:40 minidsp-shd go-librespot[32569]: time="2024-05-07T12:07:40+08:00" level=debug msg="new websocket client"
May 07 12:07:40 minidsp-shd volumio[694]: info: Connection to go-librespot Websocket established
May 07 12:07:40 minidsp-shd go-librespot[32569]: time="2024-05-07T12:07:40+08:00" level=debug msg="completed challenge"
May 07 12:07:40 minidsp-shd go-librespot[32569]: time="2024-05-07T12:07:40+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
May 07 12:07:40 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
May 07 12:07:40 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
May 07 12:07:40 minidsp-shd volumio[694]: info: Connection to go-librespot Websocket closed
May 07 12:07:43 minidsp-shd volumio[694]: info: Getting Spotify volume
May 07 12:07:43 minidsp-shd volumio[694]: (node:694) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
May 07 12:07:43 minidsp-shd volumio[694]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16)
May 07 12:07:43 minidsp-shd volumio[694]: (node:694) 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: 1087)
May 07 12:07:43 minidsp-shd volumio[694]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9
May 07 12:07:43 minidsp-shd volumio[694]: info: CoreCommandRouter::volumioGetState
May 07 12:07:43 minidsp-shd volumio[694]: info: CorePlayQueue::getTrack 0
May 07 12:07:43 minidsp-shd volumio[694]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90
May 07 12:07:43 minidsp-shd volumio[694]: info: Initializing connection to go-librespot Websocket
May 07 12:07:43 minidsp-shd volumio[694]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
May 07 12:07:43 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
May 07 12:07:43 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2178.
May 07 12:07:43 minidsp-shd systemd[1]: Stopped go-librespot Daemon.
May 07 12:07:43 minidsp-shd systemd[1]: Started go-librespot Daemon.
May 07 12:07:43 minidsp-shd go-librespot[32580]: Librespot-go daemon starting...
May 07 12:07:43 minidsp-shd go-librespot[32580]: time="2024-05-07T12:07:43+08:00" level=info msg="generated new device id: 2e9f3d6565e571002abc6ab8118cb455cad0a85f"
May 07 12:07:43 minidsp-shd go-librespot[32580]: time="2024-05-07T12:07:43+08:00" level=debug msg="stored credentials found for 15fjn881bvuykffqz6883c23j"
May 07 12:07:44 minidsp-shd go-librespot[32580]: time="2024-05-07T12:07:44+08:00" level=debug msg="obtained new client token: AACjuW24t0hJkKLBjJaX6JcgixRKSsHeX1WYOe2x0/Hv93c/akWN8Mc23JNelyLXkB9c1N1XpaiqW0fq+6T3ccNeUv26wsZBBXnnyXt2xqdhBJOrnIjNrsEWiRSg8AuFcfsJndTKZVg+qeBoQ9yK6o6/NOfLBMB096jGHmMWdm6UWz5yAO0rgGQPLnVAR0SB/aIKX5l/d8Tark8uBmdwNUEcpJVtbW2d2KtLycIbU08OGr0ieA3FuBfXLzYrim+Q"
May 07 12:07:45 minidsp-shd go-librespot[32580]: time="2024-05-07T12:07:45+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
May 07 12:07:46 minidsp-shd go-librespot[32580]: time="2024-05-07T12:07:46+08:00" level=debug msg="completed keyexchange"
May 07 12:07:46 minidsp-shd go-librespot[32580]: time="2024-05-07T12:07:46+08:00" level=debug msg="completed challenge"
May 07 12:07:46 minidsp-shd volumio[694]: info: Initializing connection to go-librespot Websocket
May 07 12:07:46 minidsp-shd go-librespot[32580]: time="2024-05-07T12:07:46+08:00" level=debug msg="new websocket client"
May 07 12:07:46 minidsp-shd volumio[694]: info: Connection to go-librespot Websocket established
May 07 12:07:46 minidsp-shd go-librespot[32580]: time="2024-05-07T12:07:46+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
May 07 12:07:46 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
May 07 12:07:46 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
May 07 12:07:46 minidsp-shd volumio[694]: info: Connection to go-librespot Websocket closed
May 07 12:07:49 minidsp-shd volumio[694]: info: Getting Spotify volume
May 07 12:07:49 minidsp-shd volumio[694]: (node:694) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
May 07 12:07:49 minidsp-shd volumio[694]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16)
May 07 12:07:49 minidsp-shd volumio[694]: (node:694) 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: 1088)
May 07 12:07:49 minidsp-shd volumio[694]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9
May 07 12:07:49 minidsp-shd volumio[694]: info: Initializing connection to go-librespot Websocket
May 07 12:07:49 minidsp-shd volumio[694]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
May 07 12:07:49 minidsp-shd volumio[694]: info: CoreCommandRouter::volumioGetState
May 07 12:07:49 minidsp-shd volumio[694]: info: CorePlayQueue::getTrack 0
May 07 12:07:49 minidsp-shd volumio[694]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90
May 07 12:07:49 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
May 07 12:07:49 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2179.
May 07 12:07:49 minidsp-shd systemd[1]: Stopped go-librespot Daemon.
May 07 12:07:49 minidsp-shd systemd[1]: Started go-librespot Daemon.
May 07 12:07:49 minidsp-shd go-librespot[32602]: Librespot-go daemon starting...
May 07 12:07:49 minidsp-shd go-librespot[32602]: time="2024-05-07T12:07:49+08:00" level=info msg="generated new device id: c93b36a957f32f0409f97ca91c11dcf5a7607e3a"
May 07 12:07:49 minidsp-shd go-librespot[32602]: time="2024-05-07T12:07:49+08:00" level=debug msg="stored credentials found for 15fjn881bvuykffqz6883c23j"
May 07 12:07:51 minidsp-shd go-librespot[32602]: time="2024-05-07T12:07:51+08:00" level=debug msg="obtained new client token: AAAkd96AbdoWsocLr+MdbxZOm5HjNHvcnmEYM6G+44E7v0QPpWBZN3tx3hqCsYhKqkPg+bWjHk2gIb7TJ0DDNurnexf57F4Y/Nw60o4lomkKlfycUUlMtx/ixxhGWvr94oOMA9a3XZ27m73EgJ6e/vNcVkOF8PNbJxTfSG/PEcd2rqXqRpFcQA88F4dXIGNVUDpdijlhumvscIMQQK8dBuge9PLIHdpykmFo4z+LrSkHDaaXnHh4tfjHrDHjxCc0"
May 07 12:07:52 minidsp-shd go-librespot[32602]: time="2024-05-07T12:07:52+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
May 07 12:07:52 minidsp-shd go-librespot[32602]: time="2024-05-07T12:07:52+08:00" level=debug msg="completed keyexchange"
May 07 12:07:52 minidsp-shd volumio[694]: info: Initializing connection to go-librespot Websocket
May 07 12:07:52 minidsp-shd go-librespot[32602]: time="2024-05-07T12:07:52+08:00" level=debug msg="new websocket client"
May 07 12:07:52 minidsp-shd volumio[694]: info: Connection to go-librespot Websocket established
May 07 12:07:53 minidsp-shd go-librespot[32602]: time="2024-05-07T12:07:53+08:00" level=debug msg="completed challenge"
May 07 12:07:53 minidsp-shd go-librespot[32602]: time="2024-05-07T12:07:53+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
May 07 12:07:53 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
May 07 12:07:53 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
May 07 12:07:53 minidsp-shd volumio[694]: info: Connection to go-librespot Websocket closed
May 07 12:07:55 minidsp-shd volumio[694]: info: Getting Spotify volume
May 07 12:07:55 minidsp-shd volumio[694]: (node:694) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
May 07 12:07:55 minidsp-shd volumio[694]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16)
May 07 12:07:55 minidsp-shd volumio[694]: (node:694) 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: 1089)
May 07 12:07:55 minidsp-shd volumio[694]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9
May 07 12:07:55 minidsp-shd volumio[694]: info: CoreCommandRouter::volumioGetState
May 07 12:07:55 minidsp-shd volumio[694]: info: CorePlayQueue::getTrack 0
May 07 12:07:55 minidsp-shd volumio[694]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90
May 07 12:07:56 minidsp-shd volumio[694]: info: Initializing connection to go-librespot Websocket
May 07 12:07:56 minidsp-shd volumio[694]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
May 07 12:07:56 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
May 07 12:07:56 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2180.
May 07 12:07:56 minidsp-shd systemd[1]: Stopped go-librespot Daemon.
May 07 12:07:56 minidsp-shd systemd[1]: Started go-librespot Daemon.
May 07 12:07:56 minidsp-shd go-librespot[32611]: Librespot-go daemon starting...
May 07 12:07:56 minidsp-shd go-librespot[32611]: time="2024-05-07T12:07:56+08:00" level=info msg="generated new device id: d54315a64202a74fdaf4214866a76738cc22c9e5"
May 07 12:07:56 minidsp-shd go-librespot[32611]: time="2024-05-07T12:07:56+08:00" level=debug msg="stored credentials found for 15fjn881bvuykffqz6883c23j"
May 07 12:07:57 minidsp-shd volumio[694]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
May 07 12:07:57 minidsp-shd volumio[694]: [t [Error]: A network error (such as timeout, interrupted connection or unreachable host) has occurred.] {
May 07 12:07:57 minidsp-shd volumio[694]: code: 'auth/network-request-failed',
May 07 12:07:57 minidsp-shd volumio[694]: a: null
May 07 12:07:57 minidsp-shd volumio[694]: }
May 07 12:07:57 minidsp-shd volumio[694]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
May 07 12:07:57 minidsp-shd go-librespot[32611]: time="2024-05-07T12:07:57+08:00" level=debug msg="obtained new client token: AAB7d4ahCSCZg1Ed5Of+y4S8FgqI4bSCwqbqc81+mHbXnI9l03hEOSZ49nwBzSzc0A2rr0tgmpH+kYIYwz0qc7h0w3nWk+HMIpikJt/41pL33mCQaq9SmvRlNC+fg7bmzAqeKJNHy6N9dpwIi9tIiuBVWFe+YD+ehIYZOAx5YoE6e6qP+PGXEoZ45ZwOcIFPDnsW4NuFfiyFezIZAai1kDbpzB2Z3rsY9aOlLs0je3uCq+HQfA5fydXLFZIhTRxx"
May 07 12:07:58 minidsp-shd sudo[32628]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-05-07 12:06
May 07 12:07:58 minidsp-shd sudo[32628]: pam_unix(sudo:session): session opened for user root by (uid=0)
PRETTY_NAME="Debian GNU/Linux 10 (buster)"
NAME="Debian GNU/Linux"
VERSION_ID="10"
VERSION="10 (buster)"
VERSION_CODENAME=buster
ID=debian
HOME_URL="https://www.debian.org/"
SUPPORT_URL="https://www.debian.org/support"
BUG_REPORT_URL="https://bugs.debian.org/"
VOLUMIO_BUILD_VERSION="17fcb754ddd6bd152b01008c46cc4ba1ca48bf35"
VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71"
VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1"
VOLUMIO_BE_VERSION="281cefcd7a302aa7cfba569185cf7aae19b8c376"
VOLUMIO_ARCH="armv7"
VOLUMIO_VARIANT="minidspshd"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Fri 22 Mar 2024 03:13:25 PM CET"
VOLUMIO_VERSION="3.608"
VOLUMIO_HARDWARE="nanopineo3"
VOLUMIO_DEVICENAME="Nanopi Neo3"
VOLUMIO_VENDOR="miniDSP"
VOLUMIO_MODEL="SHD"
VOLUMIO_VENDOR_MODEL="miniDSP SHD"
VOLUMIO_HASH="18533ba33f8f92d7e7e459bb30f70beb"