-- Logs begin at Sat 2024-09-07 22:06:28 BST, end at Sat 2024-09-07 23:33:38 BST. -- Sep 07 23:32:00 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 07 23:32:00 minidsp-shd volumio[724]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 23:32:03 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 07 23:32:03 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1246. Sep 07 23:32:03 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 07 23:32:03 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 07 23:32:03 minidsp-shd go-librespot[25905]: Librespot-go daemon starting... Sep 07 23:32:03 minidsp-shd go-librespot[25905]: time="2024-09-07T23:32:03+01:00" level=info msg="generated new device id: 2ad5a61cd85ece8ac615f8ab062afd8614e3f154" Sep 07 23:32:03 minidsp-shd go-librespot[25905]: time="2024-09-07T23:32:03+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 07 23:32:03 minidsp-shd go-librespot[25905]: time="2024-09-07T23:32:03+01:00" level=debug msg="obtained new client token: AACzYgFE/RlQh76OYZ6n4+6ac0fDmBJ6lV90SSMU9qkc3qtHlqDXC51tTP510lDcKEWJAJkhURRYYgfuY2fKNdKkh7BKIntdIhwmj7tNNkatoRRDUskQx5Hlg4w+ddKRwDZoip+/QimdAR9tzEaI2iyNZMx0ju92qbXdxXtqo44goGznMF5RZaj54N1UtwHSoX/xa2vah3Q2fplqXdPoVGWvMy80qH86rBkKMt5y96lZb3HMbCDna0nB1HOGdQk=" Sep 07 23:32:03 minidsp-shd go-librespot[25905]: time="2024-09-07T23:32:03+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-guc3.spotify.com:4070 ap2-gew4.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 07 23:32:03 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 07 23:32:03 minidsp-shd go-librespot[25905]: time="2024-09-07T23:32:03+01:00" level=debug msg="new websocket client" Sep 07 23:32:03 minidsp-shd volumio[724]: info: Connection to go-librespot Websocket established Sep 07 23:32:03 minidsp-shd go-librespot[25905]: time="2024-09-07T23:32:03+01:00" level=debug msg="completed keyexchange" Sep 07 23:32:04 minidsp-shd go-librespot[25905]: time="2024-09-07T23:32:04+01:00" level=debug msg="completed challenge" Sep 07 23:32:04 minidsp-shd go-librespot[25905]: time="2024-09-07T23:32:04+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 07 23:32:04 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 07 23:32:04 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 07 23:32:04 minidsp-shd volumio[724]: info: Connection to go-librespot Websocket closed Sep 07 23:32:06 minidsp-shd volumio[724]: info: Getting Spotify volume Sep 07 23:32:06 minidsp-shd volumio[724]: (node:724) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 23:32:06 minidsp-shd volumio[724]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Sep 07 23:32:06 minidsp-shd volumio[724]: (node:724) 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: 376) Sep 07 23:32:06 minidsp-shd volumio[724]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 Sep 07 23:32:06 minidsp-shd volumio[724]: info: CoreCommandRouter::volumioGetState Sep 07 23:32:06 minidsp-shd volumio[724]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 Sep 07 23:32:07 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 07 23:32:07 minidsp-shd volumio[724]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 23:32:07 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 07 23:32:07 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1247. Sep 07 23:32:07 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 07 23:32:07 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 07 23:32:07 minidsp-shd go-librespot[25921]: Librespot-go daemon starting... Sep 07 23:32:07 minidsp-shd go-librespot[25921]: time="2024-09-07T23:32:07+01:00" level=info msg="generated new device id: 51777fba7ebe6963f6841941025279699ed0eba8" Sep 07 23:32:07 minidsp-shd go-librespot[25921]: time="2024-09-07T23:32:07+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 07 23:32:07 minidsp-shd go-librespot[25921]: time="2024-09-07T23:32:07+01:00" level=debug msg="obtained new client token: AABbCDMeBCPOB+9aTEmQWa4EHKRecPiASq18oV/dbocKrehfjpTbiw2EIpdR5QBR32X8eFALc7bYuEiG1Ii3KXt+T3jemWhpNqXEnRfWvpYnkw2zLW5mPVp5IHQnpDYlDO0FwTjLiDUjBB6o0z8uFHiPQd2ebwxztkYTc4IBzs4G9qWghJ+5UPC1ChtvTuboltFx7NnDpXmhvY7H/P7gr+9/Y64+iruvDpL1UaS1GyHxlagyTcdGYPp1JbyKtvo=" Sep 07 23:32:07 minidsp-shd go-librespot[25921]: time="2024-09-07T23:32:07+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-gue1.spotify.com:4070 ap2-gew4.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 07 23:32:07 minidsp-shd go-librespot[25921]: time="2024-09-07T23:32:07+01:00" level=debug msg="completed keyexchange" Sep 07 23:32:08 minidsp-shd go-librespot[25921]: time="2024-09-07T23:32:08+01:00" level=debug msg="completed challenge" Sep 07 23:32:08 minidsp-shd go-librespot[25921]: time="2024-09-07T23:32:08+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 07 23:32:08 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 07 23:32:08 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 07 23:32:10 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 07 23:32:10 minidsp-shd volumio[724]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 23:32:11 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 07 23:32:11 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1248. Sep 07 23:32:11 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 07 23:32:11 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 07 23:32:11 minidsp-shd go-librespot[25937]: Librespot-go daemon starting... Sep 07 23:32:11 minidsp-shd go-librespot[25937]: time="2024-09-07T23:32:11+01:00" level=info msg="generated new device id: 35e737920dd8c856fe0040674522fa7da63147c7" Sep 07 23:32:11 minidsp-shd go-librespot[25937]: time="2024-09-07T23:32:11+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 07 23:32:11 minidsp-shd go-librespot[25937]: time="2024-09-07T23:32:11+01:00" level=debug msg="obtained new client token: AAA0zvixAt+D9rT99c966SHOVlAIcSjEwpncleZI0dFBIq8ZPi/N57+aNldvk7tRX9g/sSfAhGy8q/ENhtsz2j14Tt8quh4To9oScdbB8F3iCpeCy+XkwvRKG/MOQ3O3IJpUrx+Zkp0lwvpwtLAzaIvCbFZcT4Iz/dyC88tjDyxXHLezgKDVcGJRYNRGknHRKJwKLCrkrUX7l3jITtViWF3uyiBVlestcSSFdfrSFNSsLs5JcGKA+bC2WLOYsno=" Sep 07 23:32:11 minidsp-shd go-librespot[25937]: time="2024-09-07T23:32:11+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-guc3.spotify.com:4070 ap2-gue1.spotify.com:443 ap2-gew4.spotify.com:80]" Sep 07 23:32:12 minidsp-shd go-librespot[25937]: time="2024-09-07T23:32:12+01:00" level=debug msg="completed keyexchange" Sep 07 23:32:12 minidsp-shd go-librespot[25937]: time="2024-09-07T23:32:12+01:00" level=debug msg="completed challenge" Sep 07 23:32:12 minidsp-shd go-librespot[25937]: time="2024-09-07T23:32:12+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 07 23:32:12 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 07 23:32:12 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 07 23:32:13 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 07 23:32:13 minidsp-shd volumio[724]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 23:32:15 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 07 23:32:15 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1249. Sep 07 23:32:15 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 07 23:32:15 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 07 23:32:15 minidsp-shd go-librespot[25955]: Librespot-go daemon starting... Sep 07 23:32:15 minidsp-shd go-librespot[25955]: time="2024-09-07T23:32:15+01:00" level=info msg="generated new device id: 97d7c04e3220730685b5ca209c575f6012dd2d78" Sep 07 23:32:15 minidsp-shd go-librespot[25955]: time="2024-09-07T23:32:15+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 07 23:32:16 minidsp-shd go-librespot[25955]: time="2024-09-07T23:32:16+01:00" level=debug msg="obtained new client token: AADl2WINXnKErMMsjwdLA7Jxj5Y0AOOfgFRLoWpfksZbF4oDXwKRBLQcK+xIxWbjwFGl1BT2rn8HhVt8kf7OVFEoMVD83XHcWg7MI687s/6Z7q6lI5Z4J6fwamy59OGU5H3tAjNHdUoPG1M+WBUE752yWNSIVxavmcXFpyZLMtjpnJNDP5TJt05Itm/3grloL5TXduIssNUan2/vy0h9KpX4tvID8T+syXtb0ESQErznwOVQkrOjQYMqKzc/" Sep 07 23:32:16 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 07 23:32:16 minidsp-shd go-librespot[25955]: time="2024-09-07T23:32:16+01:00" level=debug msg="new websocket client" Sep 07 23:32:16 minidsp-shd volumio[724]: info: Connection to go-librespot Websocket established Sep 07 23:32:16 minidsp-shd go-librespot[25955]: time="2024-09-07T23:32:16+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-gue1.spotify.com:4070 ap2-gew4.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 07 23:32:16 minidsp-shd go-librespot[25955]: time="2024-09-07T23:32:16+01:00" level=debug msg="completed keyexchange" Sep 07 23:32:16 minidsp-shd go-librespot[25955]: time="2024-09-07T23:32:16+01:00" level=debug msg="completed challenge" Sep 07 23:32:16 minidsp-shd go-librespot[25955]: time="2024-09-07T23:32:16+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 07 23:32:16 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 07 23:32:16 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 07 23:32:16 minidsp-shd volumio[724]: info: Connection to go-librespot Websocket closed Sep 07 23:32:19 minidsp-shd volumio[724]: info: Getting Spotify volume Sep 07 23:32:19 minidsp-shd volumio[724]: (node:724) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 23:32:19 minidsp-shd volumio[724]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Sep 07 23:32:19 minidsp-shd volumio[724]: (node:724) 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: 377) Sep 07 23:32:19 minidsp-shd volumio[724]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 Sep 07 23:32:19 minidsp-shd volumio[724]: info: CoreCommandRouter::volumioGetState Sep 07 23:32:19 minidsp-shd volumio[724]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 Sep 07 23:32:19 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 07 23:32:19 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 07 23:32:19 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1250. Sep 07 23:32:19 minidsp-shd volumio[724]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 23:32:19 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 07 23:32:19 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 07 23:32:19 minidsp-shd go-librespot[25972]: Librespot-go daemon starting... Sep 07 23:32:19 minidsp-shd go-librespot[25972]: time="2024-09-07T23:32:19+01:00" level=info msg="generated new device id: 7c53398d98ca66424977fedfbbb45a5eb30f02e6" Sep 07 23:32:19 minidsp-shd go-librespot[25972]: time="2024-09-07T23:32:19+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 07 23:32:20 minidsp-shd go-librespot[25972]: time="2024-09-07T23:32:20+01:00" level=debug msg="obtained new client token: AABHlROB0sGkLc8dd39r4GtBmFxOz3S6ZohT8UVcq4I1KluVCFln9vkfDrVV1x1yQRPQAcBkCJEIKdMxXU75Ga8VdVSKnxy39NupSvU3TUH/WFPWzrO16BgR3o7vGhoPSmUDr+4my3XY39Cmw+986mhSL+Fe4BhijNPeVdlBoQn67yNqnXWrUC3QMVZIzUcwroY+5yhAutuLNFytrAEauzJzg9L+u25DfPpsOVIPNHVQVV+RAQMWwOrCLfvm" Sep 07 23:32:20 minidsp-shd go-librespot[25972]: time="2024-09-07T23:32:20+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-guc3.spotify.com:4070 ap2-gue1.spotify.com:443 ap2-gew4.spotify.com:80]" Sep 07 23:32:20 minidsp-shd go-librespot[25972]: time="2024-09-07T23:32:20+01:00" level=debug msg="completed keyexchange" Sep 07 23:32:20 minidsp-shd go-librespot[25972]: time="2024-09-07T23:32:20+01:00" level=debug msg="completed challenge" Sep 07 23:32:20 minidsp-shd go-librespot[25972]: time="2024-09-07T23:32:20+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 07 23:32:20 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 07 23:32:20 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 07 23:32:22 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 07 23:32:22 minidsp-shd volumio[724]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 23:32:24 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 07 23:32:24 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1251. Sep 07 23:32:24 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 07 23:32:24 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 07 23:32:24 minidsp-shd go-librespot[26027]: Librespot-go daemon starting... Sep 07 23:32:24 minidsp-shd go-librespot[26027]: time="2024-09-07T23:32:24+01:00" level=info msg="generated new device id: 438370f726fb36160584c48196f7c6bd4835b51d" Sep 07 23:32:24 minidsp-shd go-librespot[26027]: time="2024-09-07T23:32:24+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 07 23:32:24 minidsp-shd go-librespot[26027]: time="2024-09-07T23:32:24+01:00" level=debug msg="obtained new client token: AACFng8ebQhxKAb0fuvRCDy3sdr0ZTOrGsIGDamfBfB+LP0mq3fuUxgh5PI0u+8oiSFxrH8Lv2hrN4+c59krZ/rrOIX3Y7G469OuF0XRgwK73+CEJqm7g9f52GemIQlN2CaA+JmlI8N0WJ6M83WCVDR7hyImDTZLYJJF2aOsMUMdL6ypEoDujzh/SsXppV4YqQ6QlvtalWUfyoE+TG+WtqdXc+c8/UTzeQcySF8pXCYUFwuvTyf7M/3HaVXxvcU=" Sep 07 23:32:24 minidsp-shd go-librespot[26027]: time="2024-09-07T23:32:24+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-guc3.spotify.com:4070 ap2-gue1.spotify.com:443 ap2-gew4.spotify.com:80]" Sep 07 23:32:24 minidsp-shd go-librespot[26027]: time="2024-09-07T23:32:24+01:00" level=debug msg="completed keyexchange" Sep 07 23:32:25 minidsp-shd go-librespot[26027]: time="2024-09-07T23:32:25+01:00" level=debug msg="completed challenge" Sep 07 23:32:25 minidsp-shd go-librespot[26027]: time="2024-09-07T23:32:25+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 07 23:32:25 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 07 23:32:25 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 07 23:32:25 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 07 23:32:25 minidsp-shd volumio[724]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 23:32:28 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 07 23:32:28 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1252. Sep 07 23:32:28 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 07 23:32:28 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 07 23:32:28 minidsp-shd go-librespot[26043]: Librespot-go daemon starting... Sep 07 23:32:28 minidsp-shd go-librespot[26043]: time="2024-09-07T23:32:28+01:00" level=info msg="generated new device id: 2cc0c97894ce2a018a59e08dab41da1c53c1f8ee" Sep 07 23:32:28 minidsp-shd go-librespot[26043]: time="2024-09-07T23:32:28+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 07 23:32:28 minidsp-shd go-librespot[26043]: time="2024-09-07T23:32:28+01:00" level=debug msg="obtained new client token: AAA+Ad/megvVZjq3EzmjnY4/PGRi2JStqhsqx0k2t34JwlT8XTMVney53HB3c2JxlsMgdmTKxGux6nnsJbzbMw1lOBVkNUUa5dlodq1jFbW7v3QbY1aDKox0Rp1qf5VHA5LbBLdRpbrfsv07n3y0DQBL6h/1xkPgQNH/JUrfm9UJkfWdy4OZwH+UorOy9kRsBfbpg+rE0zAREeCoobY5IETKIyQT7TZGQtWlNB8oSq7HDEKLgqJWfz5QPf2S3kk=" Sep 07 23:32:28 minidsp-shd go-librespot[26043]: time="2024-09-07T23:32:28+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-guc3.spotify.com:4070 ap2-gue1.spotify.com:443 ap2-gew4.spotify.com:80]" Sep 07 23:32:28 minidsp-shd go-librespot[26043]: time="2024-09-07T23:32:28+01:00" level=debug msg="completed keyexchange" Sep 07 23:32:28 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 07 23:32:28 minidsp-shd go-librespot[26043]: time="2024-09-07T23:32:28+01:00" level=debug msg="new websocket client" Sep 07 23:32:28 minidsp-shd volumio[724]: info: Connection to go-librespot Websocket established Sep 07 23:32:29 minidsp-shd go-librespot[26043]: time="2024-09-07T23:32:29+01:00" level=debug msg="completed challenge" Sep 07 23:32:29 minidsp-shd go-librespot[26043]: time="2024-09-07T23:32:29+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 07 23:32:29 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 07 23:32:29 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 07 23:32:29 minidsp-shd volumio[724]: info: Connection to go-librespot Websocket closed Sep 07 23:32:31 minidsp-shd volumio[724]: info: Getting Spotify volume Sep 07 23:32:31 minidsp-shd volumio[724]: (node:724) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 23:32:31 minidsp-shd volumio[724]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Sep 07 23:32:31 minidsp-shd volumio[724]: (node:724) 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: 378) Sep 07 23:32:31 minidsp-shd volumio[724]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 Sep 07 23:32:31 minidsp-shd volumio[724]: info: CoreCommandRouter::volumioGetState Sep 07 23:32:31 minidsp-shd volumio[724]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 Sep 07 23:32:32 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 07 23:32:32 minidsp-shd volumio[724]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 23:32:32 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 07 23:32:32 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1253. Sep 07 23:32:32 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 07 23:32:32 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 07 23:32:32 minidsp-shd go-librespot[26059]: Librespot-go daemon starting... Sep 07 23:32:32 minidsp-shd go-librespot[26059]: time="2024-09-07T23:32:32+01:00" level=info msg="generated new device id: f39d0b316cce6ee3d997e9a268aa2d3cdd8591c7" Sep 07 23:32:32 minidsp-shd go-librespot[26059]: time="2024-09-07T23:32:32+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 07 23:32:32 minidsp-shd go-librespot[26059]: time="2024-09-07T23:32:32+01:00" level=debug msg="obtained new client token: AAD9Qabjt6qLtk79WsQUlChxfB0SLUXErHozqjonZnCOQypJY9Ml9JS9NWRU0iKvA3XCOYVDsLPLqyjPDS/n7FAmYYqxW1kGUF9s38ZpC5On+2iE7iuU+4q0HU3KYInrE7gzdJGw2QXcKZwTCYRvWTcqWjcoddBT5rTXbMPSsS0Ahlb+kAEv8h75jHzVDa+AvwkTc6VZMdCoquloRo0x17ga5lKVfP0IRm4FYp691tfiNPwiCIZznp8u6mFPyoE=" Sep 07 23:32:32 minidsp-shd go-librespot[26059]: time="2024-09-07T23:32:32+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-guc3.spotify.com:4070 ap2-gue1.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 07 23:32:32 minidsp-shd go-librespot[26059]: time="2024-09-07T23:32:32+01:00" level=debug msg="completed keyexchange" Sep 07 23:32:33 minidsp-shd go-librespot[26059]: time="2024-09-07T23:32:33+01:00" level=debug msg="completed challenge" Sep 07 23:32:33 minidsp-shd go-librespot[26059]: time="2024-09-07T23:32:33+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 07 23:32:33 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 07 23:32:33 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 07 23:32:35 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 07 23:32:35 minidsp-shd volumio[724]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 23:32:36 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 07 23:32:36 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1254. Sep 07 23:32:36 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 07 23:32:36 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 07 23:32:36 minidsp-shd go-librespot[26075]: Librespot-go daemon starting... Sep 07 23:32:36 minidsp-shd go-librespot[26075]: time="2024-09-07T23:32:36+01:00" level=info msg="generated new device id: 7bccf6f8da1c5d1f553108b94162ff251f421e36" Sep 07 23:32:36 minidsp-shd go-librespot[26075]: time="2024-09-07T23:32:36+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 07 23:32:36 minidsp-shd go-librespot[26075]: time="2024-09-07T23:32:36+01:00" level=debug msg="obtained new client token: AADIVH/1xUlpSSkpGr2pv4LMo/7AA+9Lj7DYm+50jU53DLi8kgx13LAdiHIxR55XpDyHC2PQXKgSA4igHIangqU2K6BNF3jcbSzCjvGXQ3Kjj47DjPKrssNHFr4jLXhkpk6b2s6zUiGy42q81ygo6DbZQHy6rvE9elTKVobrMxRjFfn7c8XGYtJpKFUxJUupAHSCDnFu+EKfzsL1PcJE9hJcMOmKDaDBEz0tvVUAQPJIezkWA+K/g4eiIagCstw=" Sep 07 23:32:36 minidsp-shd go-librespot[26075]: time="2024-09-07T23:32:36+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-guc3.spotify.com:4070 ap2-gew4.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 07 23:32:37 minidsp-shd go-librespot[26075]: time="2024-09-07T23:32:37+01:00" level=debug msg="completed keyexchange" Sep 07 23:32:37 minidsp-shd go-librespot[26075]: time="2024-09-07T23:32:37+01:00" level=debug msg="completed challenge" Sep 07 23:32:37 minidsp-shd go-librespot[26075]: time="2024-09-07T23:32:37+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 07 23:32:37 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 07 23:32:37 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 07 23:32:38 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 07 23:32:38 minidsp-shd volumio[724]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 23:32:40 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 07 23:32:40 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1255. Sep 07 23:32:40 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 07 23:32:40 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 07 23:32:40 minidsp-shd go-librespot[26091]: Librespot-go daemon starting... Sep 07 23:32:40 minidsp-shd go-librespot[26091]: time="2024-09-07T23:32:40+01:00" level=info msg="generated new device id: 49dc4c0f91641c62ebec756f3fb8ea2317ffe6e7" Sep 07 23:32:40 minidsp-shd go-librespot[26091]: time="2024-09-07T23:32:40+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 07 23:32:41 minidsp-shd go-librespot[26091]: time="2024-09-07T23:32:41+01:00" level=debug msg="obtained new client token: AABHqBB5HyWRgWuheKXfwultHCPa3V8FUfMsXnmuM5+bwgrz+D2yJA5ZXmHcQ0ccJPHuikFV4pYti0fsvErRb55yor1HRahpXSbmSDPmPvhTH171xyVOD0AYsl4ezS5lc/ju+6TVWH/XnvwxNKWVR+7sjLlYcZG9KD4qge9Isvc1b2G5L45Xul7Iea+QotOgt8uI07UtB/rY7ocgAfPQcrDui3dlDBshoocxnNdNR7S7CuUPDI6cfJCY009K" Sep 07 23:32:41 minidsp-shd go-librespot[26091]: time="2024-09-07T23:32:41+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-guc3.spotify.com:4070 ap2-gue1.spotify.com:443 ap2-gew4.spotify.com:80]" Sep 07 23:32:41 minidsp-shd go-librespot[26091]: time="2024-09-07T23:32:41+01:00" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed dialing accesspoint: dial tcp 104.199.65.9:4070: connect: connection refused" Sep 07 23:32:41 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 07 23:32:41 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 07 23:32:41 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 07 23:32:41 minidsp-shd volumio[724]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 23:32:44 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 07 23:32:44 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1256. Sep 07 23:32:44 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 07 23:32:44 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 07 23:32:44 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 07 23:32:44 minidsp-shd volumio[724]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 23:32:44 minidsp-shd go-librespot[26108]: Librespot-go daemon starting... Sep 07 23:32:44 minidsp-shd go-librespot[26108]: time="2024-09-07T23:32:44+01:00" level=info msg="generated new device id: 091efd3365df04074ee236473c4ea1ac3e59591c" Sep 07 23:32:44 minidsp-shd go-librespot[26108]: time="2024-09-07T23:32:44+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 07 23:32:44 minidsp-shd go-librespot[26108]: time="2024-09-07T23:32:44+01:00" level=debug msg="obtained new client token: AACVu2Br+uO5K5vdK7owAVuNZXQgE5qxbaX0j2mD0tbjoGF+R2QQOFFytzL3cUH0O/DrUyVlwtYmm3rVdU12fzGnqIZ7e/vjre7AA0pi9Uh3bbCN5sHeX5iq3CCw8oUDPDpoHdFfI/tenlLfS8OM2Bm1cu0SubIZdHi58/fz7lpOXti8tc/QzIOBlqX7QGiO0YY6P6OMaTrfbKXVnCMCLIFtDhyn7rvCn7wOhDSOnPP6OOeYdKzSYtmmVqLs4ew=" Sep 07 23:32:44 minidsp-shd go-librespot[26108]: time="2024-09-07T23:32:44+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-guc3.spotify.com:4070 ap2-gue1.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 07 23:32:44 minidsp-shd go-librespot[26108]: time="2024-09-07T23:32:44+01:00" level=debug msg="completed keyexchange" Sep 07 23:32:45 minidsp-shd go-librespot[26108]: time="2024-09-07T23:32:45+01:00" level=debug msg="completed challenge" Sep 07 23:32:45 minidsp-shd go-librespot[26108]: time="2024-09-07T23:32:45+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 07 23:32:45 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 07 23:32:45 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 07 23:32:47 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 07 23:32:47 minidsp-shd volumio[724]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 23:32:48 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 07 23:32:48 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1257. Sep 07 23:32:48 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 07 23:32:48 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 07 23:32:48 minidsp-shd go-librespot[26124]: Librespot-go daemon starting... Sep 07 23:32:48 minidsp-shd go-librespot[26124]: time="2024-09-07T23:32:48+01:00" level=info msg="generated new device id: 5022a673d55a819330ee484b13eb3cdf4c7adc9f" Sep 07 23:32:48 minidsp-shd go-librespot[26124]: time="2024-09-07T23:32:48+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 07 23:32:48 minidsp-shd go-librespot[26124]: time="2024-09-07T23:32:48+01:00" level=debug msg="obtained new client token: AACbFSbnFcS5igC6Q0JnW45+Yg93yXqihC70G7VOYHMmOU6bN0WdtQCP7jZA1s3W7RX4NfseyzpWMb8joT6AWEoaZcsNnGmr0KJiTHqSWR2JGaxBiWWW3lP8d7sSctKldSSE8QRWDgYCXqO6QNkKjJK2/pXo3/aDhxT9FpPW0cH9a+Nhf5t8jLshRMbKDktq/OQEJiav7Kok8NmQvlAhDZWXkSGzb7o9X+FhBsuHaavl7m3JX+Du2T05uLIVsXQ=" Sep 07 23:32:48 minidsp-shd go-librespot[26124]: time="2024-09-07T23:32:48+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-guc3.spotify.com:4070 ap2-gue1.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 07 23:32:49 minidsp-shd go-librespot[26124]: time="2024-09-07T23:32:49+01:00" level=debug msg="completed keyexchange" Sep 07 23:32:49 minidsp-shd go-librespot[26124]: time="2024-09-07T23:32:49+01:00" level=debug msg="completed challenge" Sep 07 23:32:49 minidsp-shd go-librespot[26124]: time="2024-09-07T23:32:49+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 07 23:32:49 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 07 23:32:49 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 07 23:32:50 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 07 23:32:50 minidsp-shd volumio[724]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 23:32:52 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 07 23:32:52 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1258. Sep 07 23:32:52 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 07 23:32:52 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 07 23:32:52 minidsp-shd go-librespot[26140]: Librespot-go daemon starting... Sep 07 23:32:52 minidsp-shd go-librespot[26140]: time="2024-09-07T23:32:52+01:00" level=info msg="generated new device id: 409906fb40f257515f6cb545e119647cccbb5834" Sep 07 23:32:52 minidsp-shd go-librespot[26140]: time="2024-09-07T23:32:52+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 07 23:32:52 minidsp-shd go-librespot[26140]: time="2024-09-07T23:32:52+01:00" level=debug msg="obtained new client token: AAAu4AzdA49U0xfiOEEKM3MAJE9Q0PqEs4p7cBHCS6B+n0xvY4V4V0RAZzDHdWy0t/S0D+VmnWAJhii1LjOWkOulSGjMxQJugzjtftrIzkE00N15rfoPWVRC7csh0yPd9ZEar03P8XhZgpy4YoNjvRRCBIDmIDreBUDB/0zQXRR9BCbEw2JGC6DQ69Vx6QANN6yfdjVGy0KfJKXTsVSkGAtJojcWDMJmOjNSVJH/KPlU41RpoUUrly3ObY5ERRI=" Sep 07 23:32:52 minidsp-shd go-librespot[26140]: time="2024-09-07T23:32:52+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-gue1.spotify.com:4070 ap2-gew4.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 07 23:32:53 minidsp-shd go-librespot[26140]: time="2024-09-07T23:32:53+01:00" level=debug msg="completed keyexchange" Sep 07 23:32:53 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 07 23:32:53 minidsp-shd go-librespot[26140]: time="2024-09-07T23:32:53+01:00" level=debug msg="new websocket client" Sep 07 23:32:53 minidsp-shd volumio[724]: info: Connection to go-librespot Websocket established Sep 07 23:32:53 minidsp-shd go-librespot[26140]: time="2024-09-07T23:32:53+01:00" level=debug msg="completed challenge" Sep 07 23:32:53 minidsp-shd go-librespot[26140]: time="2024-09-07T23:32:53+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 07 23:32:53 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 07 23:32:53 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 07 23:32:53 minidsp-shd volumio[724]: info: Connection to go-librespot Websocket closed Sep 07 23:32:56 minidsp-shd volumio[724]: info: Getting Spotify volume Sep 07 23:32:56 minidsp-shd volumio[724]: (node:724) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 23:32:56 minidsp-shd volumio[724]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Sep 07 23:32:56 minidsp-shd volumio[724]: (node:724) 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: 379) Sep 07 23:32:56 minidsp-shd volumio[724]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 Sep 07 23:32:56 minidsp-shd volumio[724]: info: CoreCommandRouter::volumioGetState Sep 07 23:32:56 minidsp-shd volumio[724]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 Sep 07 23:32:56 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 07 23:32:56 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 07 23:32:56 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1259. Sep 07 23:32:56 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 07 23:32:56 minidsp-shd volumio[724]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 23:32:56 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 07 23:32:56 minidsp-shd go-librespot[26156]: Librespot-go daemon starting... Sep 07 23:32:56 minidsp-shd go-librespot[26156]: time="2024-09-07T23:32:56+01:00" level=info msg="generated new device id: 892b47017aa96d39fe878b6172e4f9bc342920ef" Sep 07 23:32:56 minidsp-shd go-librespot[26156]: time="2024-09-07T23:32:56+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 07 23:32:56 minidsp-shd go-librespot[26156]: time="2024-09-07T23:32:56+01:00" level=debug msg="obtained new client token: AAAkRIU+R0vZp/IMb/P/QcLb00V/8HXCdOlnZ5HPRIQ34G4QpJYcQ9hB77cqp4iEHQAAr+5twZgNwikrEdM34JYSQDhe9tmZXJJTNUhB+twTLIDgAYQuURyNXH9CNii2SDI9ku2TvTefEVUYdIuF08xL95/ObIkaHdxFGzrLa2XD5fNTIy2DaUlWrbXuXjpGRSshqX5Ofn3IPMoNq6BCm0ktDljb/gRzwG3FDF/Ng2xf/hWh7V5UEMDVitNfA+Y=" Sep 07 23:32:56 minidsp-shd go-librespot[26156]: time="2024-09-07T23:32:56+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-gue1.spotify.com:4070 ap2-gew4.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 07 23:32:57 minidsp-shd go-librespot[26156]: time="2024-09-07T23:32:57+01:00" level=debug msg="completed keyexchange" Sep 07 23:32:57 minidsp-shd go-librespot[26156]: time="2024-09-07T23:32:57+01:00" level=debug msg="completed challenge" Sep 07 23:32:57 minidsp-shd go-librespot[26156]: time="2024-09-07T23:32:57+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 07 23:32:57 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 07 23:32:57 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 07 23:32:59 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 07 23:32:59 minidsp-shd volumio[724]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 23:33:00 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 07 23:33:00 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1260. Sep 07 23:33:00 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 07 23:33:00 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 07 23:33:00 minidsp-shd go-librespot[26172]: Librespot-go daemon starting... Sep 07 23:33:00 minidsp-shd go-librespot[26172]: time="2024-09-07T23:33:00+01:00" level=info msg="generated new device id: 3b14f90183a14e2cfeda333c39a0615a8e0cba70" Sep 07 23:33:00 minidsp-shd go-librespot[26172]: time="2024-09-07T23:33:00+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 07 23:33:01 minidsp-shd go-librespot[26172]: time="2024-09-07T23:33:01+01:00" level=debug msg="obtained new client token: AABY8qhqmi+9CgvTuU80I4G1vLILZGt86tg0X6RMuySJFGG1Mh1LfpN3vgGMwihaz53rVViRr6oH45o9q+5J/K8qQapG1b3xfWC4DvZ1YD6jDXZRPUsLnEiC4x2ZWLBXMbo4VCTr1/U54O+HcmIZw4Ulwn4DdgOrvJedC/u7O2LEKcjC44nzb41/gAQgSVQsyCl9mBuiw0vzSrsz4/ZXgfrHgvQjZ4f3+x/re3P6DYAU6m0bVPMpobFys9bd" Sep 07 23:33:01 minidsp-shd go-librespot[26172]: time="2024-09-07T23:33:01+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-guc3.spotify.com:4070 ap2-gue1.spotify.com:443 ap2-gew4.spotify.com:80]" Sep 07 23:33:01 minidsp-shd go-librespot[26172]: time="2024-09-07T23:33:01+01:00" level=debug msg="completed keyexchange" Sep 07 23:33:01 minidsp-shd go-librespot[26172]: time="2024-09-07T23:33:01+01:00" level=debug msg="completed challenge" Sep 07 23:33:01 minidsp-shd go-librespot[26172]: time="2024-09-07T23:33:01+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 07 23:33:01 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 07 23:33:01 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 07 23:33:02 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 07 23:33:02 minidsp-shd volumio[724]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 23:33:05 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 07 23:33:05 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1261. Sep 07 23:33:05 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 07 23:33:05 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 07 23:33:05 minidsp-shd go-librespot[26188]: Librespot-go daemon starting... Sep 07 23:33:05 minidsp-shd go-librespot[26188]: time="2024-09-07T23:33:05+01:00" level=info msg="generated new device id: 1bf09a57a48897bf7db35d1ee3fb4f0556270e5b" Sep 07 23:33:05 minidsp-shd go-librespot[26188]: time="2024-09-07T23:33:05+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 07 23:33:05 minidsp-shd go-librespot[26188]: time="2024-09-07T23:33:05+01:00" level=debug msg="obtained new client token: AABUEqPoXLymz9JB16KUz/7IjThsoiVEO7GrcvCIJoWl0bVl6q8Fa304p93K5ztAZ91jiHby8Vkj/hA6OHbm5Qr6ufRLXsaHlusesJa/4dyowMMDUPe+a/HgRqeIXGOxxfYIzA/43OjLmf+U9jXYSPYqQtEu0jUmd+8R20l3clV7zrc3w7cz9lie0cP41BNqlKQ89IsmOs688Zju0qfokgpFDL3HSMle6xF5gpTARoNVYxzjH0G2nRrali1u9Ic=" Sep 07 23:33:05 minidsp-shd go-librespot[26188]: time="2024-09-07T23:33:05+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-guc3.spotify.com:4070 ap2-gue1.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 07 23:33:05 minidsp-shd go-librespot[26188]: time="2024-09-07T23:33:05+01:00" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed dialing accesspoint: dial tcp 104.199.65.9:4070: connect: connection refused" Sep 07 23:33:05 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 07 23:33:05 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 07 23:33:05 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 07 23:33:05 minidsp-shd volumio[724]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 23:33:08 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 07 23:33:08 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1262. Sep 07 23:33:08 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 07 23:33:08 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 07 23:33:08 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 07 23:33:08 minidsp-shd go-librespot[26203]: Librespot-go daemon starting... Sep 07 23:33:08 minidsp-shd volumio[724]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 23:33:08 minidsp-shd go-librespot[26203]: time="2024-09-07T23:33:08+01:00" level=info msg="generated new device id: 9eea197447ea79f3ee7df077fb84d529bd410298" Sep 07 23:33:08 minidsp-shd go-librespot[26203]: time="2024-09-07T23:33:08+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 07 23:33:08 minidsp-shd go-librespot[26203]: time="2024-09-07T23:33:08+01:00" level=debug msg="obtained new client token: AADjpw5TaIVohsL04i7Oxy4KkR6EJ6U5hKWjb5Xfj2h98ZkOdXyg6eiPORpHOUwp1Xvtj69jnILmFbLZnQJlj526JQ/V2B05Mgm9w8OPfCBmJvY4vU5usw52/UI2CKVRXT7Qz+TGQIO7llG3sMybSoPnJQb/6QrsX4hLtQR3G5rTNS7VnZVYjEKnB/4rCj9/GoQnYtHa/H8lTt7XuAdeLoWAvagqajGiJAEOsiM9+ZfzYKpZC/MjdWbMXAjCw6I=" Sep 07 23:33:08 minidsp-shd go-librespot[26203]: time="2024-09-07T23:33:08+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-gue1.spotify.com:4070 ap2-gew4.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 07 23:33:09 minidsp-shd go-librespot[26203]: time="2024-09-07T23:33:09+01:00" level=debug msg="completed keyexchange" Sep 07 23:33:09 minidsp-shd go-librespot[26203]: time="2024-09-07T23:33:09+01:00" level=debug msg="completed challenge" Sep 07 23:33:09 minidsp-shd go-librespot[26203]: time="2024-09-07T23:33:09+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 07 23:33:09 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 07 23:33:09 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 07 23:33:10 minidsp-shd volumio[724]: verbose: New Socket.io Connection to 192.168.1.210 from 192.168.1.93 UA: unknown Total Clients: 7 Sep 07 23:33:10 minidsp-shd volumio[724]: info: CoreCommandRouter::volumioGetState Sep 07 23:33:10 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Sep 07 23:33:10 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Sep 07 23:33:11 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 07 23:33:11 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 07 23:33:11 minidsp-shd volumio[724]: info: Discovery: Getting this device information Sep 07 23:33:11 minidsp-shd volumio[724]: info: CoreCommandRouter::volumioGetState Sep 07 23:33:11 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 07 23:33:11 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 07 23:33:11 minidsp-shd volumio[724]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 23:33:12 minidsp-shd volumio[724]: verbose: New Socket.io Connection to 192.168.1.210 from 192.168.1.93 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Total Clients: 8 Sep 07 23:33:12 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Sep 07 23:33:12 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Sep 07 23:33:12 minidsp-shd volumio[724]: info: CoreCommandRouter::volumioGetVisibleSources Sep 07 23:33:12 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 07 23:33:12 minidsp-shd volumio[724]: info: CoreCommandRouter::volumioGetState Sep 07 23:33:12 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Sep 07 23:33:12 minidsp-shd volumio[724]: info: CoreCommandRouter::volumioGetQueue Sep 07 23:33:12 minidsp-shd volumio[724]: info: CoreStateMachine::getQueue Sep 07 23:33:12 minidsp-shd volumio[724]: info: CorePlayQueue::getQueue Sep 07 23:33:12 minidsp-shd volumio[724]: info: Listing playlists Sep 07 23:33:12 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Sep 07 23:33:12 minidsp-shd volumio[724]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Sep 07 23:33:12 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: inputs , handleBrowseUri Sep 07 23:33:12 minidsp-shd volumio[724]: info: Received Get System Info Sep 07 23:33:12 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 07 23:33:12 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 07 23:33:12 minidsp-shd volumio[724]: info: Discovery: Getting this device information Sep 07 23:33:12 minidsp-shd volumio[724]: info: CoreCommandRouter::volumioGetState Sep 07 23:33:12 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 07 23:33:12 minidsp-shd volumio[724]: info: CoreCommandRouter::volumioGetState Sep 07 23:33:12 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Sep 07 23:33:12 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 07 23:33:12 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1263. Sep 07 23:33:12 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 07 23:33:12 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 07 23:33:12 minidsp-shd go-librespot[26221]: Librespot-go daemon starting... Sep 07 23:33:12 minidsp-shd go-librespot[26221]: time="2024-09-07T23:33:12+01:00" level=info msg="generated new device id: fad080b9f34dc349f701ca6f4388ec6c9245c966" Sep 07 23:33:12 minidsp-shd go-librespot[26221]: time="2024-09-07T23:33:12+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 07 23:33:13 minidsp-shd go-librespot[26221]: time="2024-09-07T23:33:13+01:00" level=debug msg="obtained new client token: AAAbEQIdL/oGAf0nl+OIrhkD0imADZPTKtiFoxYP9ihxMub445Yp7Gov62/ZH019V8kAiHU9sMMWMmSWFEfDcRfltm2qzPaf2YqrEZhxZPSx/vcXaTU5DQ5tXFbmtY9zxJSNL+iWv9irWf7xWcdpGWShuTeoIeaKKa2pqfumVezWshUlQlvUKpOayb/B6Zd4i0BLDeZbIY/jXIT5tIyaTjIhMNDgHQhQJ539Lysl5EoBkXMDEOLPFVokeTdh" Sep 07 23:33:13 minidsp-shd go-librespot[26221]: time="2024-09-07T23:33:13+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-guc3.spotify.com:4070 ap2-gue1.spotify.com:443 ap2-gew4.spotify.com:80]" Sep 07 23:33:13 minidsp-shd go-librespot[26221]: time="2024-09-07T23:33:13+01:00" level=debug msg="completed keyexchange" Sep 07 23:33:13 minidsp-shd go-librespot[26221]: time="2024-09-07T23:33:13+01:00" level=debug msg="completed challenge" Sep 07 23:33:13 minidsp-shd go-librespot[26221]: time="2024-09-07T23:33:13+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 07 23:33:13 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 07 23:33:13 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 07 23:33:14 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 07 23:33:14 minidsp-shd volumio[724]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 23:33:17 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 07 23:33:17 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1264. Sep 07 23:33:17 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 07 23:33:17 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 07 23:33:17 minidsp-shd go-librespot[26238]: Librespot-go daemon starting... Sep 07 23:33:17 minidsp-shd go-librespot[26238]: time="2024-09-07T23:33:17+01:00" level=info msg="generated new device id: a11170e0142de3eb588d2cefeb9266dac6cd79f7" Sep 07 23:33:17 minidsp-shd go-librespot[26238]: time="2024-09-07T23:33:17+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 07 23:33:17 minidsp-shd go-librespot[26238]: time="2024-09-07T23:33:17+01:00" level=debug msg="obtained new client token: AAA1gAGQvWXOlzUQY+ety8H7wyivR/de9XNytGVoHl/fFpE3BRQa0fLmzKtBfa95JyaAzy3pE8pWFo5ZejdL7iWXYQkqXX3Xk6tRVAQw9p6qnpasAl6e4dZKer77WnuxzEZAzl4Ml7HvHITe9HRqyI3DSuO1DjkNx+VIiVEKLUwl6dYBccMDY8TYO0BDyCRpWdLto8/gaheLpif4srHdsQ49i91hydrAspcvBxblkiygtMP23qTGOdQKA6JaJT0=" Sep 07 23:33:17 minidsp-shd go-librespot[26238]: time="2024-09-07T23:33:17+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-guc3.spotify.com:4070 ap2-gue1.spotify.com:443 ap2-gew4.spotify.com:80]" Sep 07 23:33:17 minidsp-shd go-librespot[26238]: time="2024-09-07T23:33:17+01:00" level=debug msg="completed keyexchange" Sep 07 23:33:17 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 07 23:33:17 minidsp-shd go-librespot[26238]: time="2024-09-07T23:33:17+01:00" level=debug msg="new websocket client" Sep 07 23:33:17 minidsp-shd volumio[724]: info: Connection to go-librespot Websocket established Sep 07 23:33:18 minidsp-shd go-librespot[26238]: time="2024-09-07T23:33:18+01:00" level=debug msg="completed challenge" Sep 07 23:33:18 minidsp-shd go-librespot[26238]: time="2024-09-07T23:33:18+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 07 23:33:18 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 07 23:33:18 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 07 23:33:18 minidsp-shd volumio[724]: info: Connection to go-librespot Websocket closed Sep 07 23:33:20 minidsp-shd volumio[724]: info: Getting Spotify volume Sep 07 23:33:20 minidsp-shd volumio[724]: (node:724) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 23:33:20 minidsp-shd volumio[724]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Sep 07 23:33:20 minidsp-shd volumio[724]: (node:724) 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: 380) Sep 07 23:33:20 minidsp-shd volumio[724]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Sep 07 23:33:20 minidsp-shd volumio[724]: info: CoreCommandRouter::volumioGetState Sep 07 23:33:20 minidsp-shd volumio[724]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 Sep 07 23:33:21 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 07 23:33:21 minidsp-shd volumio[724]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 23:33:21 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 07 23:33:21 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1265. Sep 07 23:33:21 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 07 23:33:21 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 07 23:33:21 minidsp-shd go-librespot[26254]: Librespot-go daemon starting... Sep 07 23:33:21 minidsp-shd go-librespot[26254]: time="2024-09-07T23:33:21+01:00" level=info msg="generated new device id: aa09c0477b6c1d65791ef57a234ddc1af4e36bad" Sep 07 23:33:21 minidsp-shd go-librespot[26254]: time="2024-09-07T23:33:21+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 07 23:33:21 minidsp-shd go-librespot[26254]: time="2024-09-07T23:33:21+01:00" level=debug msg="obtained new client token: AACsuuMy9dGMYup5qfLRMYZXvtg0WNID7yFMc/DOdZ95u6UT6p6st0fX3v1cIBdoKidMdxvzgGeTk7dMY2d1LkrkN2ItoFNqwoNB0RWJ1cSwOkybfl+0NL0M76Im6fTsNAcehlaSHXlBnaTaTE+IVPxbUkx+1r+hJORReEd0AK0jDE59+5QCK9gbTTF32qWlDkCgLxapGxAS3QrWswlcBUAWOXp0WtPJYyqB34cMIe7gu3/Cvd9/2WjKGEaeMRI=" Sep 07 23:33:21 minidsp-shd go-librespot[26254]: time="2024-09-07T23:33:21+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-guc3.spotify.com:4070 ap2-gew4.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 07 23:33:21 minidsp-shd go-librespot[26254]: time="2024-09-07T23:33:21+01:00" level=debug msg="completed keyexchange" Sep 07 23:33:22 minidsp-shd go-librespot[26254]: time="2024-09-07T23:33:22+01:00" level=debug msg="completed challenge" Sep 07 23:33:22 minidsp-shd go-librespot[26254]: time="2024-09-07T23:33:22+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 07 23:33:22 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 07 23:33:22 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 07 23:33:24 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 07 23:33:24 minidsp-shd volumio[724]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 23:33:25 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 07 23:33:25 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1266. Sep 07 23:33:25 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 07 23:33:25 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 07 23:33:25 minidsp-shd go-librespot[26308]: Librespot-go daemon starting... Sep 07 23:33:25 minidsp-shd go-librespot[26308]: time="2024-09-07T23:33:25+01:00" level=info msg="generated new device id: 289f89011c334cb711fad4f12894ab818e21726b" Sep 07 23:33:25 minidsp-shd go-librespot[26308]: time="2024-09-07T23:33:25+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 07 23:33:25 minidsp-shd go-librespot[26308]: time="2024-09-07T23:33:25+01:00" level=debug msg="obtained new client token: AACEwQkkCMo05/175VV6J/tYBQT/Ruk3Br2Ong/jMfXfLKjlysjmvVAUJj/0kViBtcotuXISgE9CHX6kfuw0agot2MxYePBcjxsnX6F06fiNY7Ty8UT663XzD5fWcKyKt4A/PNcMEbESbctp/8yLFOY04nMsCOKxbj0mvHsJgkHNPsYfxVLFRJijzhF9tT1NAo07YqkxxeI/JuLj2FxFsDBidIKfQ1utWEmeM36o0CfX80SBFZy+5r5EIixDfT0=" Sep 07 23:33:25 minidsp-shd go-librespot[26308]: time="2024-09-07T23:33:25+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-guc3.spotify.com:4070 ap2-gew4.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 07 23:33:26 minidsp-shd go-librespot[26308]: time="2024-09-07T23:33:26+01:00" level=debug msg="completed keyexchange" Sep 07 23:33:26 minidsp-shd go-librespot[26308]: time="2024-09-07T23:33:26+01:00" level=debug msg="completed challenge" Sep 07 23:33:26 minidsp-shd go-librespot[26308]: time="2024-09-07T23:33:26+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 07 23:33:26 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 07 23:33:26 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 07 23:33:27 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 07 23:33:27 minidsp-shd volumio[724]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 23:33:29 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 07 23:33:29 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1267. Sep 07 23:33:29 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 07 23:33:29 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 07 23:33:29 minidsp-shd go-librespot[26326]: Librespot-go daemon starting... Sep 07 23:33:29 minidsp-shd go-librespot[26326]: time="2024-09-07T23:33:29+01:00" level=info msg="generated new device id: deb8019719292ba403de47d0b931c5f1313077a0" Sep 07 23:33:29 minidsp-shd go-librespot[26326]: time="2024-09-07T23:33:29+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 07 23:33:30 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 07 23:33:30 minidsp-shd go-librespot[26326]: time="2024-09-07T23:33:30+01:00" level=debug msg="new websocket client" Sep 07 23:33:30 minidsp-shd volumio[724]: info: Connection to go-librespot Websocket established Sep 07 23:33:30 minidsp-shd go-librespot[26326]: time="2024-09-07T23:33:30+01:00" level=debug msg="obtained new client token: AAAU+oAYExbKVLj4Z9JnYI3asnXLNoga3Y11K3idcxZ46b1kJle7ZQssX9qDcjD/najrbM3NsMZpDdtld4ppF9GDu1S+AojQFq9RLCS03kQbRj7N/BZ9IZnp7pBQyVOqSMxyMNBPeAscRsriwhGUrnMLcoXXQJDXMpLNVy6FvoIGgfXebevInlGA7OwU4kkdvCFvfCS1LYbrGF2rPFfzNZTFJBq4A7c2gfX11+d5zTT1ZocmmfDwXqXohXif" Sep 07 23:33:30 minidsp-shd go-librespot[26326]: time="2024-09-07T23:33:30+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-guc3.spotify.com:4070 ap2-gue1.spotify.com:443 ap2-gew4.spotify.com:80]" Sep 07 23:33:30 minidsp-shd go-librespot[26326]: time="2024-09-07T23:33:30+01:00" level=debug msg="completed keyexchange" Sep 07 23:33:30 minidsp-shd go-librespot[26326]: time="2024-09-07T23:33:30+01:00" level=debug msg="completed challenge" Sep 07 23:33:30 minidsp-shd go-librespot[26326]: time="2024-09-07T23:33:30+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Sep 07 23:33:30 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 07 23:33:30 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 07 23:33:30 minidsp-shd volumio[724]: info: Connection to go-librespot Websocket closed Sep 07 23:33:33 minidsp-shd volumio[724]: info: Getting Spotify volume Sep 07 23:33:33 minidsp-shd volumio[724]: (node:724) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 23:33:33 minidsp-shd volumio[724]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Sep 07 23:33:33 minidsp-shd volumio[724]: (node:724) 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: 381) Sep 07 23:33:33 minidsp-shd volumio[724]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Sep 07 23:33:33 minidsp-shd volumio[724]: info: CoreCommandRouter::volumioGetState Sep 07 23:33:33 minidsp-shd volumio[724]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 Sep 07 23:33:33 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 07 23:33:33 minidsp-shd volumio[724]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 23:33:34 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 07 23:33:34 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1268. Sep 07 23:33:34 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 07 23:33:34 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 07 23:33:34 minidsp-shd go-librespot[26344]: Librespot-go daemon starting... Sep 07 23:33:34 minidsp-shd go-librespot[26344]: time="2024-09-07T23:33:34+01:00" level=info msg="generated new device id: dd98be981cff67d55216bc45aefbcdb683cd7261" Sep 07 23:33:34 minidsp-shd go-librespot[26344]: time="2024-09-07T23:33:34+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 07 23:33:34 minidsp-shd go-librespot[26344]: time="2024-09-07T23:33:34+01:00" level=debug msg="obtained new client token: AADc0cvbiuTnKoWOa/2WYCbJ7SaiE27BuSFujU/RTwUrr3Ij046DOec9TVD6X9MgbWoSXnoO/r32SuiOJNsUDeaTQvL4Z8tHQ7yJcmjdYer/KL4ZJJQxDnhNSjeKD3lL1PnE2UlnlDG0hANBJvW9pkCltGcLZVnhIh7AnTKESINlog3PuFzWzNPPUCRIm6hlU2hOvIFrO+QrmEWxicHMFiYuLvK9WT44O7Yw8CL9KkC28uWQfXgZLJJc5REQgaI=" Sep 07 23:33:34 minidsp-shd go-librespot[26344]: time="2024-09-07T23:33:34+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-gue1.spotify.com:4070 ap2-gew4.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 07 23:33:34 minidsp-shd go-librespot[26344]: time="2024-09-07T23:33:34+01:00" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed dialing accesspoint: dial tcp 104.199.65.9:4070: connect: connection refused" Sep 07 23:33:34 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 07 23:33:34 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 07 23:33:36 minidsp-shd volumio[724]: info: Initializing connection to go-librespot Websocket Sep 07 23:33:36 minidsp-shd volumio[724]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 07 23:33:37 minidsp-shd volumio[724]: Searching all installed plugins Sep 07 23:33:37 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 07 23:33:37 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: , search Sep 07 23:33:37 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: mpd , search Sep 07 23:33:37 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search Sep 07 23:33:37 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: last_100 , search Sep 07 23:33:37 minidsp-shd volumio[724]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 Sep 07 23:33:37 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: webradio , search Sep 07 23:33:37 minidsp-shd volumio[724]: info: CoreCommandRouter::executeOnPlugin: calmradio , search Sep 07 23:33:37 minidsp-shd volumio[724]: info: [1725748417372] ControllerCalmRadio::searchCategories Sep 07 23:33:37 minidsp-shd volumio[724]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 07 23:33:37 minidsp-shd volumio[724]: TypeError: Cannot read property 'cats' of undefined Sep 07 23:33:37 minidsp-shd volumio[724]: at ControllerCalmRadio.searchCategories (/data/plugins/music_service/calmradio/index.js:615:42) Sep 07 23:33:37 minidsp-shd volumio[724]: at ControllerCalmRadio.search (/data/plugins/music_service/calmradio/index.js:665:28) Sep 07 23:33:37 minidsp-shd volumio[724]: at CoreCommandRouter.executeOnPlugin (/volumio/app/index.js:1077:32) Sep 07 23:33:37 minidsp-shd volumio[724]: at CoreMusicLibrary.searchOnPlugin (/volumio/app/musiclibrary.js:668:44) Sep 07 23:33:37 minidsp-shd volumio[724]: at CoreMusicLibrary.search (/volumio/app/musiclibrary.js:455:27) Sep 07 23:33:37 minidsp-shd volumio[724]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:457:44) Sep 07 23:33:37 minidsp-shd volumio[724]: at Socket.emit (events.js:400:28) Sep 07 23:33:37 minidsp-shd volumio[724]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 Sep 07 23:33:37 minidsp-shd volumio[724]: at processTicksAndRejections (internal/process/task_queues.js:77:11) Sep 07 23:33:37 minidsp-shd volumio[724]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 07 23:33:37 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 07 23:33:37 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1269. Sep 07 23:33:37 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 07 23:33:37 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 07 23:33:37 minidsp-shd go-librespot[26366]: Librespot-go daemon starting... Sep 07 23:33:37 minidsp-shd go-librespot[26366]: time="2024-09-07T23:33:37+01:00" level=info msg="generated new device id: 866d42b31320e2d0b65febfd4d15349ddb2faff7" Sep 07 23:33:37 minidsp-shd go-librespot[26366]: time="2024-09-07T23:33:37+01:00" level=debug msg="stored credentials found for lbhj574own4f1tcjm2qey9a4g" Sep 07 23:33:37 minidsp-shd go-librespot[26366]: time="2024-09-07T23:33:37+01:00" level=debug msg="obtained new client token: AABxh8yYd7OJMDu3htjJOmr9ljc/Ps2Xdxw/FWze0mmhfm3vXvEjp8RlYAVkoFEI8omy6raL2SsXnssd77r1VzFQSO85bujCMp/WD9/e+ZtpUKtl0lAoyQMNnCWL3Eo2lFSpc5d9RUG9pX/zrbgAGYQTD4ufj4GfkEyCIGAyAUZ4MymfhdvJhTlYvceVnH/TcSq4jhMHhMGoTbepwxntChmI/VMCEBHMWD4a98pjN/1gEe07cbxQEALZY6daO7s=" Sep 07 23:33:38 minidsp-shd go-librespot[26366]: time="2024-09-07T23:33:38+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-guc3.spotify.com:4070 ap2-gue1.spotify.com:443 ap2-gew4.spotify.com:80]" Sep 07 23:33:38 minidsp-shd go-librespot[26366]: time="2024-09-07T23:33:38+01:00" level=debug msg="completed keyexchange" Sep 07 23:33:38 minidsp-shd sudo[26375]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-09-07 23:32 Sep 07 23:33:38 minidsp-shd sudo[26375]: 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:00:28 PM CET" VOLUMIO_VERSION="3.608" VOLUMIO_HARDWARE="nanopineo2" VOLUMIO_DEVICENAME="NanoPi Neo2" VOLUMIO_VENDOR="miniDSP" VOLUMIO_MODEL="SHD" VOLUMIO_VENDOR_MODEL="miniDSP SHD" VOLUMIO_HASH="29ccfe8a9cff19911db4b736879ac117"