-- Logs begin at Thu 2019-02-14 05:11:59 EST, end at Fri 2024-07-05 19:59:01 EDT. -- Jul 05 19:58:00 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 19:58:00 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 34. Jul 05 19:58:00 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Jul 05 19:58:00 minidsp-shd systemd[1]: Started go-librespot Daemon. Jul 05 19:58:00 minidsp-shd go-librespot[1649]: Librespot-go daemon starting... Jul 05 19:58:00 minidsp-shd go-librespot[1649]: time="2024-07-05T19:58:00-04:00" level=info msg="generated new device id: 77c8458759f852b426e287970b2ee54ec3903da7" Jul 05 19:58:00 minidsp-shd go-librespot[1649]: time="2024-07-05T19:58:00-04:00" level=debug msg="stored credentials found for jmdahl13" Jul 05 19:58:00 minidsp-shd go-librespot[1649]: time="2024-07-05T19:58:00-04:00" level=debug msg="obtained new client token: AACbDHv6/m9w8UfNU9XChhSGLrLi5yIPsutbb3I+vW14+9Tr02/6mwV4SD9ZtN3NlFjwo+oH6RpaWh+KTAe2FZgxIDPXaG9x460KesCuoEV0n0JUIVducPy0Wh1Wg3EabzF5lcQS1F0uWBu1nKMWq3E0piAmbhPl6Vi6ltG3dljcP3hNhVZSmUEr7wvwXxNJhoAe9Ih7L+XduNmpfe9FpESLcZDPuT73e7gmE/lXH+l5AjFrL2AFMTWDpSD1Ls9AIA==" Jul 05 19:58:00 minidsp-shd volumio[619]: info: Initializing connection to go-librespot Websocket Jul 05 19:58:00 minidsp-shd go-librespot[1649]: time="2024-07-05T19:58:00-04:00" level=debug msg="new websocket client" Jul 05 19:58:00 minidsp-shd volumio[619]: info: Connection to go-librespot Websocket established Jul 05 19:58:01 minidsp-shd go-librespot[1649]: time="2024-07-05T19:58:01-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 19:58:01 minidsp-shd go-librespot[1649]: time="2024-07-05T19:58:01-04:00" level=debug msg="completed keyexchange" Jul 05 19:58:01 minidsp-shd go-librespot[1649]: time="2024-07-05T19:58:01-04:00" level=debug msg="completed challenge" Jul 05 19:58:01 minidsp-shd go-librespot[1649]: time="2024-07-05T19:58:01-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 05 19:58:01 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 19:58:01 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 19:58:01 minidsp-shd volumio[619]: info: Connection to go-librespot Websocket closed Jul 05 19:58:04 minidsp-shd volumio[619]: info: Getting Spotify volume Jul 05 19:58:04 minidsp-shd volumio[619]: (node:619) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 19:58:04 minidsp-shd volumio[619]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Jul 05 19:58:04 minidsp-shd volumio[619]: (node:619) 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: 12) Jul 05 19:58:04 minidsp-shd volumio[619]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 10 Jul 05 19:58:04 minidsp-shd volumio[619]: info: CoreCommandRouter::volumioGetState Jul 05 19:58:04 minidsp-shd volumio[619]: SPOTIFY: RECEIVED VOLUMIO VOLUME 76 Jul 05 19:58:04 minidsp-shd volumio[619]: info: Initializing connection to go-librespot Websocket Jul 05 19:58:04 minidsp-shd volumio[619]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 19:58:04 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 19:58:04 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 35. Jul 05 19:58:04 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Jul 05 19:58:04 minidsp-shd systemd[1]: Started go-librespot Daemon. Jul 05 19:58:04 minidsp-shd go-librespot[1657]: Librespot-go daemon starting... Jul 05 19:58:04 minidsp-shd go-librespot[1657]: time="2024-07-05T19:58:04-04:00" level=info msg="generated new device id: 28cbb84c4328de7525ce6479d5d7c4bf86d90e7a" Jul 05 19:58:04 minidsp-shd go-librespot[1657]: time="2024-07-05T19:58:04-04:00" level=debug msg="stored credentials found for jmdahl13" Jul 05 19:58:05 minidsp-shd go-librespot[1657]: time="2024-07-05T19:58:05-04:00" level=debug msg="obtained new client token: AACL8tx0YlNbgGenrpSgxr0oVttKhmEbCqLTr8YeZS4pnX50mqWhJ7jrBYGOOU1WpgKMJ5D+jD3q8x9RDfqGfQ8g6WK0jruvqktZXpFdNtE7bvMLfLIBbN1KqJiqf0xkkxMyqCmv+U0tCDB90yMcjBr98K4uVWtxwKANPaoG+0OA4URmhw0/V2wxKKvLzFS2p34kaqxLn53oM812cd3lLmDvpWSx708JDViFnuHqdOIsTIcxgf97HVmfaZowzAc=" Jul 05 19:58:05 minidsp-shd go-librespot[1657]: time="2024-07-05T19:58:05-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 19:58:05 minidsp-shd go-librespot[1657]: time="2024-07-05T19:58:05-04:00" level=debug msg="completed keyexchange" Jul 05 19:58:05 minidsp-shd go-librespot[1657]: time="2024-07-05T19:58:05-04:00" level=debug msg="completed challenge" Jul 05 19:58:05 minidsp-shd go-librespot[1657]: time="2024-07-05T19:58:05-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 05 19:58:05 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 19:58:05 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 19:58:07 minidsp-shd volumio[619]: info: Initializing connection to go-librespot Websocket Jul 05 19:58:07 minidsp-shd volumio[619]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 19:58:09 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 19:58:09 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 36. Jul 05 19:58:09 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Jul 05 19:58:09 minidsp-shd systemd[1]: Started go-librespot Daemon. Jul 05 19:58:09 minidsp-shd go-librespot[1665]: Librespot-go daemon starting... Jul 05 19:58:09 minidsp-shd go-librespot[1665]: time="2024-07-05T19:58:09-04:00" level=info msg="generated new device id: 4a3c9b774de8aa3f0f93de63fd548a7bbd9dfa06" Jul 05 19:58:09 minidsp-shd go-librespot[1665]: time="2024-07-05T19:58:09-04:00" level=debug msg="stored credentials found for jmdahl13" Jul 05 19:58:09 minidsp-shd go-librespot[1665]: time="2024-07-05T19:58:09-04:00" level=debug msg="obtained new client token: AAAlbdMIr827KaBGdf1uRST6s2LnPcS6OcsHsZMmeEMLLC1i3AgNywcD0Avc5Q8k1Hl9vYOdLaKnAztJ0d0LHu3u4SoBI76127G34jWNqgKAxYWsXgrLLFdGD7XX0KWUowNE9dlAGZLP4FrfGX5Kn/pDNsu6qJw+ElTeQpR7lOZ3QnUdKOLymIjiDAVZXdr0PZaBuIVRlS3VFl593snOR34fA/mqxCBbBFlsNCu6/SYbgfZe4fpGDfJTVOI7zS6RrQ==" Jul 05 19:58:09 minidsp-shd go-librespot[1665]: time="2024-07-05T19:58:09-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 19:58:09 minidsp-shd go-librespot[1665]: time="2024-07-05T19:58:09-04:00" level=debug msg="completed keyexchange" Jul 05 19:58:10 minidsp-shd go-librespot[1665]: time="2024-07-05T19:58:10-04:00" level=debug msg="completed challenge" Jul 05 19:58:10 minidsp-shd go-librespot[1665]: time="2024-07-05T19:58:10-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 05 19:58:10 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 19:58:10 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 19:58:10 minidsp-shd volumio[619]: info: Initializing connection to go-librespot Websocket Jul 05 19:58:10 minidsp-shd volumio[619]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 19:58:13 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 19:58:13 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 37. Jul 05 19:58:13 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Jul 05 19:58:13 minidsp-shd systemd[1]: Started go-librespot Daemon. Jul 05 19:58:13 minidsp-shd go-librespot[1673]: Librespot-go daemon starting... Jul 05 19:58:13 minidsp-shd go-librespot[1673]: time="2024-07-05T19:58:13-04:00" level=info msg="generated new device id: 22e9c08945a04dfdcdb974a1a001cccdfecb552e" Jul 05 19:58:13 minidsp-shd go-librespot[1673]: time="2024-07-05T19:58:13-04:00" level=debug msg="stored credentials found for jmdahl13" Jul 05 19:58:13 minidsp-shd go-librespot[1673]: time="2024-07-05T19:58:13-04:00" level=debug msg="obtained new client token: AABmv4P3NOQnDf1qwCfVE9cmU/YWeMvWnGghBbobpKbxo6qWce2HKRt8hx3q7xfm266gCogjrylKvCjJv70Yxg623Pjm6r3LQlUdQ5FEKa8mwFGW0pE8wV4ZLA1g14D2NCFgde6Iogzkd2PN3sv2QCSGWv6WYKz8DjK022wyeHIPc5MLA+iE5XL3lk19nphOuhiH6gH4QfNXsgKgP9k7DikYpc5JsHV++8hNaOViszpkd7GAjxpgWFWvFxqlZlRPQA==" Jul 05 19:58:13 minidsp-shd volumio[619]: info: Initializing connection to go-librespot Websocket Jul 05 19:58:13 minidsp-shd go-librespot[1673]: time="2024-07-05T19:58:13-04:00" level=debug msg="new websocket client" Jul 05 19:58:13 minidsp-shd go-librespot[1673]: time="2024-07-05T19:58:13-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 19:58:13 minidsp-shd volumio[619]: info: Connection to go-librespot Websocket established Jul 05 19:58:14 minidsp-shd go-librespot[1673]: time="2024-07-05T19:58:14-04:00" level=debug msg="completed keyexchange" Jul 05 19:58:15 minidsp-shd go-librespot[1673]: time="2024-07-05T19:58:15-04:00" level=debug msg="completed challenge" Jul 05 19:58:15 minidsp-shd go-librespot[1673]: time="2024-07-05T19:58:15-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 05 19:58:15 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 19:58:15 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 19:58:15 minidsp-shd volumio[619]: info: Connection to go-librespot Websocket closed Jul 05 19:58:16 minidsp-shd volumio[619]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 05 19:58:16 minidsp-shd volumio[619]: /bin/cat: /sys/class/net/wlan0/flags: No such file or directory Jul 05 19:58:16 minidsp-shd volumio[619]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jul 05 19:58:16 minidsp-shd volumio[619]: info: Getting Spotify volume Jul 05 19:58:16 minidsp-shd volumio[619]: (node:619) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 19:58:16 minidsp-shd volumio[619]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Jul 05 19:58:16 minidsp-shd volumio[619]: (node:619) 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: 13) Jul 05 19:58:16 minidsp-shd volumio[619]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 10 Jul 05 19:58:16 minidsp-shd volumio[619]: info: CoreCommandRouter::volumioGetState Jul 05 19:58:16 minidsp-shd volumio[619]: SPOTIFY: RECEIVED VOLUMIO VOLUME 76 Jul 05 19:58:16 minidsp-shd volumio[619]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork Jul 05 19:58:17 minidsp-shd sudo[1685]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 Jul 05 19:58:17 minidsp-shd sudo[1685]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 05 19:58:17 minidsp-shd sudo[1685]: pam_unix(sudo:session): session closed for user root Jul 05 19:58:17 minidsp-shd sudo[1690]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Jul 05 19:58:17 minidsp-shd sudo[1690]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 05 19:58:17 minidsp-shd sudo[1698]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Jul 05 19:58:17 minidsp-shd sudo[1698]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 05 19:58:17 minidsp-shd sudo[1690]: pam_unix(sudo:session): session closed for user root Jul 05 19:58:17 minidsp-shd sudo[1705]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Jul 05 19:58:17 minidsp-shd sudo[1705]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 05 19:58:17 minidsp-shd sudo[1698]: pam_unix(sudo:session): session closed for user root Jul 05 19:58:17 minidsp-shd sudo[1716]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jul 05 19:58:17 minidsp-shd sudo[1716]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 05 19:58:17 minidsp-shd volumio[619]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworksScanCache Jul 05 19:58:17 minidsp-shd volumio[619]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworks Jul 05 19:58:17 minidsp-shd sudo[1716]: pam_unix(sudo:session): session closed for user root Jul 05 19:58:17 minidsp-shd sudo[1705]: pam_unix(sudo:session): session closed for user root Jul 05 19:58:17 minidsp-shd sudo[1725]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jul 05 19:58:17 minidsp-shd sudo[1725]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 05 19:58:17 minidsp-shd sudo[1725]: pam_unix(sudo:session): session closed for user root Jul 05 19:58:17 minidsp-shd sudo[1730]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jul 05 19:58:17 minidsp-shd sudo[1730]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 05 19:58:17 minidsp-shd sudo[1730]: pam_unix(sudo:session): session closed for user root Jul 05 19:58:17 minidsp-shd volumio[619]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Jul 05 19:58:17 minidsp-shd volumio[619]: wlan0 Interface doesn't support scanning. Jul 05 19:58:17 minidsp-shd volumio[619]: info: Cannot use regular scanning, forcing with ap-force Jul 05 19:58:17 minidsp-shd sudo[1736]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Jul 05 19:58:17 minidsp-shd sudo[1736]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 05 19:58:17 minidsp-shd sudo[1736]: pam_unix(sudo:session): session closed for user root Jul 05 19:58:17 minidsp-shd volumio[619]: command failed: No such device (-19) Jul 05 19:58:17 minidsp-shd volumio[619]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force Jul 05 19:58:17 minidsp-shd volumio[619]: command failed: No such device (-19) Jul 05 19:58:18 minidsp-shd volumio[619]: info: Initializing connection to go-librespot Websocket Jul 05 19:58:18 minidsp-shd volumio[619]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 19:58:18 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 19:58:18 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38. Jul 05 19:58:18 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Jul 05 19:58:18 minidsp-shd systemd[1]: Started go-librespot Daemon. Jul 05 19:58:18 minidsp-shd go-librespot[1740]: Librespot-go daemon starting... Jul 05 19:58:18 minidsp-shd go-librespot[1740]: time="2024-07-05T19:58:18-04:00" level=info msg="generated new device id: 8d87737d0faf7907778d741c556c667cf16be2c8" Jul 05 19:58:18 minidsp-shd go-librespot[1740]: time="2024-07-05T19:58:18-04:00" level=debug msg="stored credentials found for jmdahl13" Jul 05 19:58:18 minidsp-shd go-librespot[1740]: time="2024-07-05T19:58:18-04:00" level=debug msg="obtained new client token: AAAJiTXwDrokdApEXDGqioAhQtRnKCpztbOOMAEOcYuH90MDgYLKUJRV+cGzdfO7cd0BsjjUoRb3NXQHYoyarG6ZPlaCVZbQsiTahQtcWSBeSVNsKtwEIR3Lp7jNRY16jWkV49JAcg+eobIk9w9Am1XAF6wb2FxZODRLulWWoiw6urqmZHpjmCiUvobaMiqSTP3GJ4c6qaZIrm+isbIWVOR0pJ+RMChBBgT/Fl1LANrVQP7tEMBnbn/EE7cCj1WH+A==" Jul 05 19:58:18 minidsp-shd go-librespot[1740]: time="2024-07-05T19:58:18-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 19:58:18 minidsp-shd go-librespot[1740]: time="2024-07-05T19:58:18-04:00" level=debug msg="completed keyexchange" Jul 05 19:58:19 minidsp-shd go-librespot[1740]: time="2024-07-05T19:58:19-04:00" level=debug msg="completed challenge" Jul 05 19:58:19 minidsp-shd go-librespot[1740]: time="2024-07-05T19:58:19-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 05 19:58:19 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 19:58:19 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 19:58:21 minidsp-shd volumio[619]: info: Initializing connection to go-librespot Websocket Jul 05 19:58:21 minidsp-shd volumio[619]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 19:58:22 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 19:58:22 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 39. Jul 05 19:58:22 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Jul 05 19:58:22 minidsp-shd systemd[1]: Started go-librespot Daemon. Jul 05 19:58:22 minidsp-shd go-librespot[1748]: Librespot-go daemon starting... Jul 05 19:58:22 minidsp-shd go-librespot[1748]: time="2024-07-05T19:58:22-04:00" level=info msg="generated new device id: 7d0e5edf9d4abea4cfda4d20f7434496577cfb04" Jul 05 19:58:22 minidsp-shd go-librespot[1748]: time="2024-07-05T19:58:22-04:00" level=debug msg="stored credentials found for jmdahl13" Jul 05 19:58:22 minidsp-shd go-librespot[1748]: time="2024-07-05T19:58:22-04:00" level=debug msg="obtained new client token: AABrhtN6MMIzSLcT8nFb+N+tT5Um6udJ+z9bdqOFMS6z8kLxHG4wP0H+gpevDrVr2n9VBgyRFMcK70Dme4b3jutx0UuBknxTgvfqusMakAouoFHCRhVo+kwHD0LGnLJL+xE+SnlYSwgtWZi07IKv1n8HtYOUHGNrqvmo85JRrk2PG/suz98r+sOzZ4CJlMLq7Vci3joNVEo5tIfWw/awfe2zbojvDWjNko0rfRkS53xtWNFG7fha/eQjQP3vudKTgw==" Jul 05 19:58:23 minidsp-shd go-librespot[1748]: time="2024-07-05T19:58:23-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 19:58:23 minidsp-shd go-librespot[1748]: time="2024-07-05T19:58:23-04:00" level=debug msg="completed keyexchange" Jul 05 19:58:23 minidsp-shd go-librespot[1748]: time="2024-07-05T19:58:23-04:00" level=debug msg="completed challenge" Jul 05 19:58:23 minidsp-shd go-librespot[1748]: time="2024-07-05T19:58:23-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 05 19:58:23 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 19:58:23 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 19:58:24 minidsp-shd volumio[619]: info: Initializing connection to go-librespot Websocket Jul 05 19:58:24 minidsp-shd volumio[619]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 19:58:26 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 19:58:26 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 40. Jul 05 19:58:26 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Jul 05 19:58:26 minidsp-shd systemd[1]: Started go-librespot Daemon. Jul 05 19:58:26 minidsp-shd go-librespot[1756]: Librespot-go daemon starting... Jul 05 19:58:26 minidsp-shd go-librespot[1756]: time="2024-07-05T19:58:26-04:00" level=info msg="generated new device id: b7598a6919e5ad6a48e09554cebe39a72f51ea0c" Jul 05 19:58:26 minidsp-shd go-librespot[1756]: time="2024-07-05T19:58:26-04:00" level=debug msg="stored credentials found for jmdahl13" Jul 05 19:58:27 minidsp-shd volumio[619]: info: Initializing connection to go-librespot Websocket Jul 05 19:58:27 minidsp-shd go-librespot[1756]: time="2024-07-05T19:58:27-04:00" level=debug msg="new websocket client" Jul 05 19:58:27 minidsp-shd volumio[619]: info: Connection to go-librespot Websocket established Jul 05 19:58:27 minidsp-shd go-librespot[1756]: time="2024-07-05T19:58:27-04:00" level=debug msg="obtained new client token: AAAmShgxl/78h+v8hRPNdTfKKL4ZnKd/T6aIqmvdJuVib5UJmXn7qm43iaqxVA4y4XcLrxbQp5HK5kGYsafrPmAdsEv91sgWt9QZAOokK2H8J8wdtHawxdb+WasZ6u25GK9V9WGNJz/X7cYiXcKmTZpA+2DMg4x3ab+vTQv4D68ZMsM77DaYz1dUMGsY6tWgmKEUe/4PocS0KFttCbjdNo1Q2waaJTudN9v2WiXnHX0YBCsDIrFfelqnoXr6i5c=" Jul 05 19:58:27 minidsp-shd go-librespot[1756]: time="2024-07-05T19:58:27-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 19:58:27 minidsp-shd go-librespot[1756]: time="2024-07-05T19:58:27-04:00" level=debug msg="completed keyexchange" Jul 05 19:58:27 minidsp-shd go-librespot[1756]: time="2024-07-05T19:58:27-04:00" level=debug msg="completed challenge" Jul 05 19:58:27 minidsp-shd go-librespot[1756]: time="2024-07-05T19:58:27-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 05 19:58:27 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 19:58:27 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 19:58:27 minidsp-shd volumio[619]: info: Connection to go-librespot Websocket closed Jul 05 19:58:30 minidsp-shd volumio[619]: info: Getting Spotify volume Jul 05 19:58:30 minidsp-shd volumio[619]: (node:619) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 19:58:30 minidsp-shd volumio[619]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Jul 05 19:58:30 minidsp-shd volumio[619]: (node:619) 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: 14) Jul 05 19:58:30 minidsp-shd volumio[619]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 10 Jul 05 19:58:30 minidsp-shd volumio[619]: info: CoreCommandRouter::volumioGetState Jul 05 19:58:30 minidsp-shd volumio[619]: SPOTIFY: RECEIVED VOLUMIO VOLUME 76 Jul 05 19:58:30 minidsp-shd volumio[619]: info: Initializing connection to go-librespot Websocket Jul 05 19:58:30 minidsp-shd volumio[619]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 19:58:31 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 19:58:31 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 41. Jul 05 19:58:31 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Jul 05 19:58:31 minidsp-shd systemd[1]: Started go-librespot Daemon. Jul 05 19:58:31 minidsp-shd go-librespot[1764]: Librespot-go daemon starting... Jul 05 19:58:31 minidsp-shd go-librespot[1764]: time="2024-07-05T19:58:31-04:00" level=info msg="generated new device id: 0a9978662c64eb01679f78a4ec33824d5c2aa644" Jul 05 19:58:31 minidsp-shd go-librespot[1764]: time="2024-07-05T19:58:31-04:00" level=debug msg="stored credentials found for jmdahl13" Jul 05 19:58:31 minidsp-shd go-librespot[1764]: time="2024-07-05T19:58:31-04:00" level=debug msg="obtained new client token: AABQv5o73Jk5ErVGfKnGbly5OPUshHYQt4hA85D+cB3jLCKgCtHvnyMs+zpI9lrgyCxAAlmduFYIrrtIrWxyiZquvJW++DYm7uuK6zEdyj0FfMTO3Sw6xBft5dZMpkXTKYtsE9UtUnrIpJb1EHBmGBgMkZ90XAsa03tsj5hZQV1X8viPc0dcVPWOs8PkQzg0Eqlc2zwGxlcgJUm0GkVzdV1e6O965ju44YRxWl+sDn0qhvaWuWpqzSmxd8+bYvAdbw==" Jul 05 19:58:31 minidsp-shd go-librespot[1764]: time="2024-07-05T19:58:31-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 19:58:31 minidsp-shd go-librespot[1764]: time="2024-07-05T19:58:31-04:00" level=debug msg="completed keyexchange" Jul 05 19:58:32 minidsp-shd go-librespot[1764]: time="2024-07-05T19:58:32-04:00" level=debug msg="completed challenge" Jul 05 19:58:32 minidsp-shd go-librespot[1764]: time="2024-07-05T19:58:32-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 05 19:58:32 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 19:58:32 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 19:58:33 minidsp-shd volumio[619]: info: Initializing connection to go-librespot Websocket Jul 05 19:58:34 minidsp-shd volumio[619]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 19:58:35 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 19:58:35 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 42. Jul 05 19:58:35 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Jul 05 19:58:35 minidsp-shd systemd[1]: Started go-librespot Daemon. Jul 05 19:58:35 minidsp-shd go-librespot[1773]: Librespot-go daemon starting... Jul 05 19:58:35 minidsp-shd go-librespot[1773]: time="2024-07-05T19:58:35-04:00" level=info msg="generated new device id: 0d38571be9efc865ab4db890b98984751ad29a15" Jul 05 19:58:35 minidsp-shd go-librespot[1773]: time="2024-07-05T19:58:35-04:00" level=debug msg="stored credentials found for jmdahl13" Jul 05 19:58:35 minidsp-shd go-librespot[1773]: time="2024-07-05T19:58:35-04:00" level=debug msg="obtained new client token: AACh0kjKJJa0JQLDwTbQDi4PLGnW7enVHUdO2FWa73gmKGtgeOgWlGyNA8539wWVAynPc6i/BXX/YlsT2YXUfEBHc6qVMqxVDaWtMsxKJf7Zn3ap/w/b5ZwaJ6nCroiDVJHB+qp237oyUJlQ4vK9xY6IQsgSpNdWuSAxv/dU3oByIyxwg3r4srIkkg+8DJGwtbAn6pQpKi6I9YUNpC9S4yBYKrEEjB1nEwwn05AfqYcffwtnQJp+1vya/dEerpDqWg==" Jul 05 19:58:35 minidsp-shd go-librespot[1773]: time="2024-07-05T19:58:35-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 19:58:35 minidsp-shd go-librespot[1773]: time="2024-07-05T19:58:35-04:00" level=debug msg="completed keyexchange" Jul 05 19:58:36 minidsp-shd go-librespot[1773]: time="2024-07-05T19:58:36-04:00" level=debug msg="completed challenge" Jul 05 19:58:36 minidsp-shd go-librespot[1773]: time="2024-07-05T19:58:36-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 05 19:58:36 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 19:58:36 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 19:58:37 minidsp-shd volumio[619]: info: Initializing connection to go-librespot Websocket Jul 05 19:58:37 minidsp-shd volumio[619]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 19:58:39 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 19:58:39 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 43. Jul 05 19:58:39 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Jul 05 19:58:39 minidsp-shd systemd[1]: Started go-librespot Daemon. Jul 05 19:58:39 minidsp-shd go-librespot[1781]: Librespot-go daemon starting... Jul 05 19:58:39 minidsp-shd go-librespot[1781]: time="2024-07-05T19:58:39-04:00" level=info msg="generated new device id: c7414d7137ae8ae5fe387b5e94376d2d975ff40e" Jul 05 19:58:39 minidsp-shd go-librespot[1781]: time="2024-07-05T19:58:39-04:00" level=debug msg="stored credentials found for jmdahl13" Jul 05 19:58:39 minidsp-shd go-librespot[1781]: time="2024-07-05T19:58:39-04:00" level=debug msg="obtained new client token: AACVybUktAQRgkSNoe4p3fku963zxW6xsvR63oLwoEwigd47try+PGFWcqF8FeaHKUvpPKLiGMVE+pZYSdndv441DeKQaNjFG8XVGVgQ+Ys7AdVd+ZaG0Qq8hhwnzqHiUmKiLb3/G333EPHXuunVFm7aICaJxb7oqCB1IfJcJNfL+odYd+jlyxSNDDZh6AaRo9/xBG2oJNIfarU/vqXnRLK3rjPSX+yAVOXJmW1OKBUztJR+aNS5Y2mZhq/2tInB0Q==" Jul 05 19:58:40 minidsp-shd volumio[619]: info: Initializing connection to go-librespot Websocket Jul 05 19:58:40 minidsp-shd go-librespot[1781]: time="2024-07-05T19:58:40-04:00" level=debug msg="new websocket client" Jul 05 19:58:40 minidsp-shd volumio[619]: info: Connection to go-librespot Websocket established Jul 05 19:58:40 minidsp-shd go-librespot[1781]: time="2024-07-05T19:58:40-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 19:58:40 minidsp-shd go-librespot[1781]: time="2024-07-05T19:58:40-04:00" level=debug msg="completed keyexchange" Jul 05 19:58:40 minidsp-shd go-librespot[1781]: time="2024-07-05T19:58:40-04:00" level=debug msg="completed challenge" Jul 05 19:58:40 minidsp-shd go-librespot[1781]: time="2024-07-05T19:58:40-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 05 19:58:40 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 19:58:40 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 19:58:40 minidsp-shd volumio[619]: info: Connection to go-librespot Websocket closed Jul 05 19:58:42 minidsp-shd volumio[619]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 05 19:58:42 minidsp-shd volumio[619]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 05 19:58:42 minidsp-shd volumio[619]: info: Retrieving Cloud Streaming UI Jul 05 19:58:42 minidsp-shd volumio[619]: info: Getting Tidal Cloud Configuration Jul 05 19:58:42 minidsp-shd volumio[619]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 05 19:58:42 minidsp-shd volumio[619]: info: Getting Qobuz Cloud Configuration Jul 05 19:58:42 minidsp-shd volumio[619]: info: Asking plugin for UI Config Jul 05 19:58:42 minidsp-shd volumio[619]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 05 19:58:42 minidsp-shd volumio[619]: info: Getting Spotify Cloud Configuration Jul 05 19:58:42 minidsp-shd volumio[619]: info: Asking plugin for UI Config Jul 05 19:58:42 minidsp-shd volumio[619]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 05 19:58:42 minidsp-shd volumio[619]: info: Saving Spotify Acccount Jul 05 19:58:42 minidsp-shd volumio[619]: info: Got it Jul 05 19:58:42 minidsp-shd volumio[619]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Jul 05 19:58:42 minidsp-shd volumio[619]: info: Got Tidal Cloud Configuration Jul 05 19:58:42 minidsp-shd volumio[619]: info: Got it Jul 05 19:58:42 minidsp-shd volumio[619]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 05 19:58:42 minidsp-shd volumio[619]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jul 05 19:58:42 minidsp-shd volumio[619]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jul 05 19:58:42 minidsp-shd volumio[619]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jul 05 19:58:42 minidsp-shd volumio[619]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jul 05 19:58:42 minidsp-shd volumio[619]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 05 19:58:42 minidsp-shd volumio[619]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 05 19:58:42 minidsp-shd volumio[619]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 05 19:58:42 minidsp-shd volumio[619]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 05 19:58:42 minidsp-shd volumio[619]: info: CoreCommandRouter::volumioGetBrowseSources Jul 05 19:58:42 minidsp-shd volumio[619]: info: CoreCommandRouter::volumioGetBrowseSources Jul 05 19:58:42 minidsp-shd volumio[619]: info: CoreCommandRouter::volumioGetBrowseSources Jul 05 19:58:42 minidsp-shd volumio[619]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jul 05 19:58:42 minidsp-shd volumio[619]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Jul 05 19:58:43 minidsp-shd volumio[619]: info: Getting Spotify volume Jul 05 19:58:43 minidsp-shd volumio[619]: (node:619) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 19:58:43 minidsp-shd volumio[619]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Jul 05 19:58:43 minidsp-shd volumio[619]: (node:619) 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: 15) Jul 05 19:58:43 minidsp-shd volumio[619]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 10 Jul 05 19:58:43 minidsp-shd volumio[619]: info: CoreCommandRouter::volumioGetState Jul 05 19:58:43 minidsp-shd volumio[619]: SPOTIFY: RECEIVED VOLUMIO VOLUME 76 Jul 05 19:58:43 minidsp-shd volumio[619]: info: Initializing connection to go-librespot Websocket Jul 05 19:58:43 minidsp-shd volumio[619]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 19:58:43 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 19:58:43 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 44. Jul 05 19:58:43 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Jul 05 19:58:43 minidsp-shd systemd[1]: Started go-librespot Daemon. Jul 05 19:58:43 minidsp-shd go-librespot[1789]: Librespot-go daemon starting... Jul 05 19:58:43 minidsp-shd go-librespot[1789]: time="2024-07-05T19:58:43-04:00" level=info msg="generated new device id: 52eafc26385cc22b0ef0ec8c3800ccbf5c324435" Jul 05 19:58:43 minidsp-shd go-librespot[1789]: time="2024-07-05T19:58:43-04:00" level=debug msg="stored credentials found for jmdahl13" Jul 05 19:58:44 minidsp-shd go-librespot[1789]: time="2024-07-05T19:58:44-04:00" level=debug msg="obtained new client token: AADllyVeqdETKPfTSRzLX7M/+MWb/oZNErddHMKM38YYV2nprvy+usw1LWkeT27EjPdLH1m+KkkqE3oBmSRTC2GJyVnR5ZNlphwPdptT6puQKqtdRaZ61KZc6m0Jtla+s9wDozTTCBzhK8+6mwz0BXlEQC96kj1Vd9RSKlGvbs8loCi2IbFq9n9bpogCdSeeRaHKKUaYpyJ+ltiTv0eSMkdNUXt5X7Jk5w+lvmM0TqIaQKm0kqmbMVGV5RlLY8c=" Jul 05 19:58:44 minidsp-shd go-librespot[1789]: time="2024-07-05T19:58:44-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 19:58:44 minidsp-shd go-librespot[1789]: time="2024-07-05T19:58:44-04:00" level=debug msg="completed keyexchange" Jul 05 19:58:44 minidsp-shd go-librespot[1789]: time="2024-07-05T19:58:44-04:00" level=debug msg="completed challenge" Jul 05 19:58:44 minidsp-shd go-librespot[1789]: time="2024-07-05T19:58:44-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 05 19:58:44 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 19:58:44 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 19:58:46 minidsp-shd volumio[619]: info: Initializing connection to go-librespot Websocket Jul 05 19:58:46 minidsp-shd volumio[619]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 19:58:46 minidsp-shd volumio[619]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jul 05 19:58:48 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 19:58:48 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 45. Jul 05 19:58:48 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Jul 05 19:58:48 minidsp-shd systemd[1]: Started go-librespot Daemon. Jul 05 19:58:48 minidsp-shd go-librespot[1797]: Librespot-go daemon starting... Jul 05 19:58:48 minidsp-shd go-librespot[1797]: time="2024-07-05T19:58:48-04:00" level=info msg="generated new device id: 7338e1dd4527923ff5412247ddd0f2cb1d3c1e2c" Jul 05 19:58:48 minidsp-shd go-librespot[1797]: time="2024-07-05T19:58:48-04:00" level=debug msg="stored credentials found for jmdahl13" Jul 05 19:58:48 minidsp-shd go-librespot[1797]: time="2024-07-05T19:58:48-04:00" level=debug msg="obtained new client token: AAClLPJxipQ3u0mczhwHf8rfjf4WpDLJfPRfZzalqkY0NuBAuEeSBA1pxubTNTlVbHb8Y0WZbP7kO3BBopOVhz8DwtwSl5wb0yk6XqZtEV5sOaoHhTWJqn/sQpElnlZ4b+ISnCVXgYYQMlRPNg9h3c8w8IyT12awWAhPb2y0aVaCSPVdUFF4pftgTMDC2Xjb9Gw7RFF1bS56KCjf0/OQ4aLjElAWDKx1qoDcllNX0u8hwtgjpfgOBLPHQqMGOyZwbg==" Jul 05 19:58:48 minidsp-shd go-librespot[1797]: time="2024-07-05T19:58:48-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Jul 05 19:58:48 minidsp-shd go-librespot[1797]: time="2024-07-05T19:58:48-04:00" level=debug msg="completed keyexchange" Jul 05 19:58:49 minidsp-shd go-librespot[1797]: time="2024-07-05T19:58:49-04:00" level=debug msg="completed challenge" Jul 05 19:58:49 minidsp-shd go-librespot[1797]: time="2024-07-05T19:58:49-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 05 19:58:49 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 19:58:49 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 19:58:49 minidsp-shd volumio[619]: info: Initializing connection to go-librespot Websocket Jul 05 19:58:49 minidsp-shd volumio[619]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 19:58:52 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 19:58:52 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 46. Jul 05 19:58:52 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Jul 05 19:58:52 minidsp-shd systemd[1]: Started go-librespot Daemon. Jul 05 19:58:52 minidsp-shd go-librespot[1843]: Librespot-go daemon starting... Jul 05 19:58:52 minidsp-shd go-librespot[1843]: time="2024-07-05T19:58:52-04:00" level=info msg="generated new device id: 9f725f99ab4c89431976e59c9174d722451c47e9" Jul 05 19:58:52 minidsp-shd go-librespot[1843]: time="2024-07-05T19:58:52-04:00" level=debug msg="stored credentials found for jmdahl13" Jul 05 19:58:52 minidsp-shd go-librespot[1843]: time="2024-07-05T19:58:52-04:00" level=debug msg="obtained new client token: AADUycTzXU+aJlQgkYlgsr0bERW6HyfFgR0IgH6Zilg9deImOdTVSGiMhje9edGVTnCQEPobHXEoR49cpyFKaWkSfCAdTBYBsqnbMskhcH4XhYBu65AzY6zetrZwudbFeZSVuI+XXBMtWT+faW8fy8w45vuNC8WG+JWCRkUDK5G3bPqXixLd1Nwp9tFs0Rs/LkEd16PR/FuzsYdIaXSBc64VwsopT2+1RieSwQsB/gvEn9j9PMPsKxhMS070VAB0+A==" Jul 05 19:58:52 minidsp-shd volumio[619]: info: Initializing connection to go-librespot Websocket Jul 05 19:58:52 minidsp-shd go-librespot[1843]: time="2024-07-05T19:58:52-04:00" level=debug msg="new websocket client" Jul 05 19:58:52 minidsp-shd volumio[619]: info: Connection to go-librespot Websocket established Jul 05 19:58:52 minidsp-shd go-librespot[1843]: time="2024-07-05T19:58:52-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 19:58:52 minidsp-shd go-librespot[1843]: time="2024-07-05T19:58:52-04:00" level=debug msg="completed keyexchange" Jul 05 19:58:53 minidsp-shd go-librespot[1843]: time="2024-07-05T19:58:53-04:00" level=debug msg="completed challenge" Jul 05 19:58:53 minidsp-shd go-librespot[1843]: time="2024-07-05T19:58:53-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 05 19:58:53 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 19:58:53 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 19:58:53 minidsp-shd volumio[619]: info: Connection to go-librespot Websocket closed Jul 05 19:58:55 minidsp-shd volumio[619]: info: Getting Spotify volume Jul 05 19:58:55 minidsp-shd volumio[619]: (node:619) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 19:58:55 minidsp-shd volumio[619]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Jul 05 19:58:55 minidsp-shd volumio[619]: (node:619) 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: 16) Jul 05 19:58:55 minidsp-shd volumio[619]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 10 Jul 05 19:58:55 minidsp-shd volumio[619]: info: CoreCommandRouter::volumioGetState Jul 05 19:58:55 minidsp-shd volumio[619]: SPOTIFY: RECEIVED VOLUMIO VOLUME 76 Jul 05 19:58:56 minidsp-shd volumio[619]: info: Initializing connection to go-librespot Websocket Jul 05 19:58:56 minidsp-shd volumio[619]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 19:58:56 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 19:58:56 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 47. Jul 05 19:58:56 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Jul 05 19:58:56 minidsp-shd systemd[1]: Started go-librespot Daemon. Jul 05 19:58:56 minidsp-shd go-librespot[1852]: Librespot-go daemon starting... Jul 05 19:58:56 minidsp-shd go-librespot[1852]: time="2024-07-05T19:58:56-04:00" level=info msg="generated new device id: c22319951dc4d5ec6b15628ca9ad8eb09c9e0e81" Jul 05 19:58:56 minidsp-shd go-librespot[1852]: time="2024-07-05T19:58:56-04:00" level=debug msg="stored credentials found for jmdahl13" Jul 05 19:58:56 minidsp-shd go-librespot[1852]: time="2024-07-05T19:58:56-04:00" level=debug msg="obtained new client token: AACeBlHzo92d5o0yKsnMkcSpNaO1/UqMun7sAQHMmzmbN/QXIKR3eyvIGqoZGDZ2b1f/BkjWEUZaJ+Bt2Wg2QSNOGELVcQM3nXnlbf5wokSheLx7O91b7tvQ/8cT+MXITjDZPWTt1gaV9RfNPuWkP21mpcsHfNx0rne7TNBFMqG6XSY1ubbgnXwC/NSJvZUJsgpNfFdnlJs8fDhHU/vFy0e5EaAjhXCOUJc+V2r18aUe8qeaMQlNp1WAngNgEtz0jw==" Jul 05 19:58:57 minidsp-shd go-librespot[1852]: time="2024-07-05T19:58:57-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Jul 05 19:58:57 minidsp-shd go-librespot[1852]: time="2024-07-05T19:58:57-04:00" level=debug msg="completed keyexchange" Jul 05 19:58:57 minidsp-shd go-librespot[1852]: time="2024-07-05T19:58:57-04:00" level=debug msg="completed challenge" Jul 05 19:58:57 minidsp-shd go-librespot[1852]: time="2024-07-05T19:58:57-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 05 19:58:57 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 19:58:57 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 19:58:59 minidsp-shd volumio[619]: info: Initializing connection to go-librespot Websocket Jul 05 19:58:59 minidsp-shd volumio[619]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 19:59:00 minidsp-shd volumio[619]: info: CoreCommandRouter::volumioSeek Jul 05 19:59:00 minidsp-shd volumio[619]: info: CoreStateMachine::seek Jul 05 19:59:00 minidsp-shd volumio[619]: info: [1720223940569] inputs::seek to 0 Jul 05 19:59:00 minidsp-shd volumio[619]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 05 19:59:00 minidsp-shd volumio[619]: TypeError: this.sendSpopCommand is not a function Jul 05 19:59:00 minidsp-shd volumio[619]: at inputs.seek (/volumio/app/plugins/music_service/inputs/inputs_real:1:2486) Jul 05 19:59:00 minidsp-shd volumio[619]: at CoreStateMachine.seek (/volumio/app/statemachine.js:1084:20) Jul 05 19:59:00 minidsp-shd volumio[619]: at CoreCommandRouter.volumioSeek (/volumio/app/index.js:1421:28) Jul 05 19:59:00 minidsp-shd volumio[619]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:153:33) Jul 05 19:59:00 minidsp-shd volumio[619]: at Socket.emit (events.js:400:28) Jul 05 19:59:00 minidsp-shd volumio[619]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 Jul 05 19:59:00 minidsp-shd volumio[619]: at processTicksAndRejections (internal/process/task_queues.js:77:11) Jul 05 19:59:00 minidsp-shd volumio[619]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 05 19:59:00 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 19:59:00 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 48. Jul 05 19:59:00 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Jul 05 19:59:00 minidsp-shd systemd[1]: Started go-librespot Daemon. Jul 05 19:59:00 minidsp-shd go-librespot[1868]: Librespot-go daemon starting... Jul 05 19:59:00 minidsp-shd go-librespot[1868]: time="2024-07-05T19:59:00-04:00" level=info msg="generated new device id: 00b183f50ed8de2722b5c4fa0d72d69ad63073db" Jul 05 19:59:00 minidsp-shd go-librespot[1868]: time="2024-07-05T19:59:00-04:00" level=debug msg="stored credentials found for jmdahl13" Jul 05 19:59:01 minidsp-shd go-librespot[1868]: time="2024-07-05T19:59:01-04:00" level=debug msg="obtained new client token: AAAVr8lFHms2n3cUUEiOMDdcSkefnE0MMM2lD4k3nqf39rcs6V0kBPw2XAN70sYt+1EA+SvHd0iKrq/4OLfRv+0owCeoyxfga0vesvTF/nA7v2eZ2fwiKm9UTDR543+NcJ/6KWYRys0lFctjsuwEssnlXoYw84NpioJfdLIuU3fJcgnzNDVrf4FNF+ixE3k3n3OoEDmoEd8xTv57crcTRbyp8FiscSGOo3gESdzfsnHQMxkbwnBfVMsNpFG5xAc=" Jul 05 19:59:01 minidsp-shd go-librespot[1868]: time="2024-07-05T19:59:01-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 19:59:01 minidsp-shd go-librespot[1868]: time="2024-07-05T19:59:01-04:00" level=debug msg="completed keyexchange" Jul 05 19:59:01 minidsp-shd sudo[1877]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-07-05 19:58 Jul 05 19:59:01 minidsp-shd sudo[1877]: 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"