-- Logs begin at Fri 2024-07-05 02:00:27 BST, end at Fri 2024-07-05 04:44:08 BST. -- Jul 05 04:43:00 masterbedroom volumio[1091]: info: Initializing connection to go-librespot Websocket Jul 05 04:43:00 masterbedroom volumio[1091]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 04:43:00 masterbedroom volumio-remote-updater[652]: PROGRESS: 11, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:00 masterbedroom volumio-remote-updater[652]: PROGRESS: 11, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:00 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:00 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:00 masterbedroom volumio[1091]: { Jul 05 04:43:00 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:00 masterbedroom volumio[1091]: eta: '5m', Jul 05 04:43:00 masterbedroom volumio[1091]: progress: 11, Jul 05 04:43:00 masterbedroom volumio[1091]: status: 'Creating backup' Jul 05 04:43:00 masterbedroom volumio[1091]: } Jul 05 04:43:01 masterbedroom systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 04:43:01 masterbedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12813. Jul 05 04:43:01 masterbedroom systemd[1]: Stopped go-librespot Daemon. Jul 05 04:43:01 masterbedroom systemd[1]: Started go-librespot Daemon. Jul 05 04:43:01 masterbedroom go-librespot[11914]: Librespot-go daemon starting... Jul 05 04:43:01 masterbedroom go-librespot[11914]: time="2024-07-05T04:43:01+01:00" level=info msg="generated new device id: 59f064ca3367ac71e886dce27d3b1af85b5d0106" Jul 05 04:43:01 masterbedroom go-librespot[11914]: time="2024-07-05T04:43:01+01:00" level=debug msg="stored credentials found for arbitrabbit" Jul 05 04:43:01 masterbedroom go-librespot[11914]: time="2024-07-05T04:43:01+01:00" level=debug msg="obtained new client token: AABhpdHTsWPIEckavM1PSU5NdhOqoh5PAdgPSmSqCk1+L+hxtN2eRaIja5bVdVl4XBfwP7jPghDLWuCE5rUZeZofTCuRjDuk4W5IqYNWQjuU7gBQyQiDievQf4hZjBdEIiFKtVkBJAy8xQzn0YcqMyl2cs/Ug1Oh+v2Jd+Sv9s0c5ZKML2je/DeYIM581w40ICa7Lachkl5yTLXSNh7ZzoTcK1UTVxv9ZEy6tt15yKuT87PqLxkZKkXWd7km" Jul 05 04:43:01 masterbedroom go-librespot[11914]: time="2024-07-05T04:43:01+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jul 05 04:43:01 masterbedroom go-librespot[11914]: time="2024-07-05T04:43:01+01:00" level=debug msg="completed keyexchange" Jul 05 04:43:01 masterbedroom volumio-remote-updater[652]: PROGRESS: 11, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:01 masterbedroom volumio-remote-updater[652]: PROGRESS: 12, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:01 masterbedroom volumio-remote-updater[652]: PROGRESS: 12, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:01 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:01 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:01 masterbedroom volumio[1091]: { Jul 05 04:43:01 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:01 masterbedroom volumio[1091]: eta: '5m', Jul 05 04:43:01 masterbedroom volumio[1091]: progress: 12, Jul 05 04:43:01 masterbedroom volumio[1091]: status: 'Creating backup' Jul 05 04:43:01 masterbedroom volumio[1091]: } Jul 05 04:43:01 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:01 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:01 masterbedroom volumio[1091]: { Jul 05 04:43:01 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:01 masterbedroom volumio[1091]: eta: '5m', Jul 05 04:43:01 masterbedroom volumio[1091]: progress: 12, Jul 05 04:43:01 masterbedroom volumio[1091]: status: 'Creating backup' Jul 05 04:43:01 masterbedroom volumio[1091]: } Jul 05 04:43:02 masterbedroom go-librespot[11914]: time="2024-07-05T04:43:02+01:00" level=debug msg="completed challenge" Jul 05 04:43:02 masterbedroom go-librespot[11914]: time="2024-07-05T04:43:02+01: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 04:43:02 masterbedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 04:43:02 masterbedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 04:43:02 masterbedroom volumio-remote-updater[652]: PROGRESS: 12, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:02 masterbedroom volumio-remote-updater[652]: PROGRESS: 13, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:02 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:02 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:02 masterbedroom volumio[1091]: { Jul 05 04:43:02 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:02 masterbedroom volumio[1091]: eta: '5m', Jul 05 04:43:02 masterbedroom volumio[1091]: progress: 13, Jul 05 04:43:02 masterbedroom volumio[1091]: status: 'Creating backup' Jul 05 04:43:02 masterbedroom volumio[1091]: } Jul 05 04:43:02 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:02 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:02 masterbedroom volumio[1091]: { Jul 05 04:43:02 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:02 masterbedroom volumio[1091]: eta: '5m', Jul 05 04:43:02 masterbedroom volumio[1091]: progress: 13, Jul 05 04:43:02 masterbedroom volumio[1091]: status: 'Creating backup' Jul 05 04:43:02 masterbedroom volumio[1091]: } Jul 05 04:43:03 masterbedroom volumio[1091]: info: Initializing connection to go-librespot Websocket Jul 05 04:43:03 masterbedroom volumio[1091]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 04:43:03 masterbedroom volumio-remote-updater[652]: PROGRESS: 13, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:03 masterbedroom volumio-remote-updater[652]: PROGRESS: 13, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:03 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:03 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:03 masterbedroom volumio[1091]: { Jul 05 04:43:03 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:03 masterbedroom volumio[1091]: eta: '5m', Jul 05 04:43:03 masterbedroom volumio[1091]: progress: 13, Jul 05 04:43:03 masterbedroom volumio[1091]: status: 'Creating backup' Jul 05 04:43:03 masterbedroom volumio[1091]: } Jul 05 04:43:03 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:03 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:03 masterbedroom volumio[1091]: { Jul 05 04:43:03 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:03 masterbedroom volumio[1091]: eta: '5m', Jul 05 04:43:03 masterbedroom volumio[1091]: progress: 13, Jul 05 04:43:03 masterbedroom volumio[1091]: status: 'Creating backup' Jul 05 04:43:03 masterbedroom volumio[1091]: } Jul 05 04:43:05 masterbedroom volumio-remote-updater[652]: PROGRESS: 13, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:05 masterbedroom volumio-remote-updater[652]: PROGRESS: 13, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:05 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:05 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:05 masterbedroom volumio[1091]: { Jul 05 04:43:05 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:05 masterbedroom volumio[1091]: eta: '5m', Jul 05 04:43:05 masterbedroom volumio[1091]: progress: 13, Jul 05 04:43:05 masterbedroom volumio[1091]: status: 'Creating backup' Jul 05 04:43:05 masterbedroom volumio[1091]: } Jul 05 04:43:05 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:05 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:05 masterbedroom volumio[1091]: { Jul 05 04:43:05 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:05 masterbedroom volumio[1091]: eta: '5m', Jul 05 04:43:05 masterbedroom volumio[1091]: progress: 13, Jul 05 04:43:05 masterbedroom volumio[1091]: status: 'Creating backup' Jul 05 04:43:05 masterbedroom volumio[1091]: } Jul 05 04:43:05 masterbedroom systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 04:43:05 masterbedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12814. Jul 05 04:43:05 masterbedroom systemd[1]: Stopped go-librespot Daemon. Jul 05 04:43:05 masterbedroom systemd[1]: Started go-librespot Daemon. Jul 05 04:43:05 masterbedroom go-librespot[11922]: Librespot-go daemon starting... Jul 05 04:43:05 masterbedroom go-librespot[11922]: time="2024-07-05T04:43:05+01:00" level=info msg="generated new device id: 228e1269461f10298ac691a365c388ae56e520c6" Jul 05 04:43:05 masterbedroom go-librespot[11922]: time="2024-07-05T04:43:05+01:00" level=debug msg="stored credentials found for arbitrabbit" Jul 05 04:43:05 masterbedroom go-librespot[11922]: time="2024-07-05T04:43:05+01:00" level=debug msg="obtained new client token: AACPckUDfQhCbMPjx0Fwl5N5pJ7qKQhIgNIppRAeGqgXMmXvHdpPDJnSh/eDH4TiMCAFkpE3h3x4+z8Z2iUwqEoNUfaWP1CsIn6UWjBIBC5CVjQgDWw+G8iRt66tuZkJxXuAqSCMzJgO7MPwJTxK2IbaXitLSZAzqOssVLBWRMpZCgtF/aiZkIgkh3W+j4Gb629tzFCu62LXZq2vEGVkkcZ1xLKIfWrtJDizbgnkV1OCQVH7EZ7aWgWnkhZi" Jul 05 04:43:05 masterbedroom go-librespot[11922]: time="2024-07-05T04:43:05+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jul 05 04:43:05 masterbedroom go-librespot[11922]: time="2024-07-05T04:43:05+01:00" level=debug msg="completed keyexchange" Jul 05 04:43:06 masterbedroom volumio-remote-updater[652]: PROGRESS: 13, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:06 masterbedroom volumio-remote-updater[652]: PROGRESS: 14, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:06 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:06 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:06 masterbedroom volumio[1091]: { Jul 05 04:43:06 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:06 masterbedroom volumio[1091]: eta: '5m', Jul 05 04:43:06 masterbedroom volumio[1091]: progress: 14, Jul 05 04:43:06 masterbedroom volumio[1091]: status: 'Creating backup' Jul 05 04:43:06 masterbedroom volumio[1091]: } Jul 05 04:43:06 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:06 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:06 masterbedroom volumio[1091]: { Jul 05 04:43:06 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:06 masterbedroom volumio[1091]: eta: '5m', Jul 05 04:43:06 masterbedroom volumio[1091]: progress: 14, Jul 05 04:43:06 masterbedroom volumio[1091]: status: 'Creating backup' Jul 05 04:43:06 masterbedroom volumio[1091]: } Jul 05 04:43:06 masterbedroom go-librespot[11922]: time="2024-07-05T04:43:06+01:00" level=debug msg="completed challenge" Jul 05 04:43:06 masterbedroom go-librespot[11922]: time="2024-07-05T04:43:06+01: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 04:43:06 masterbedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 04:43:06 masterbedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 04:43:06 masterbedroom volumio[1091]: info: Initializing connection to go-librespot Websocket Jul 05 04:43:06 masterbedroom volumio[1091]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 04:43:07 masterbedroom volumio-remote-updater[652]: PROGRESS: 14, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:07 masterbedroom volumio-remote-updater[652]: PROGRESS: 15, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:07 masterbedroom volumio-remote-updater[652]: PROGRESS: 15, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:07 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:07 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:07 masterbedroom volumio[1091]: { Jul 05 04:43:07 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:07 masterbedroom volumio[1091]: eta: '5m', Jul 05 04:43:07 masterbedroom volumio[1091]: progress: 15, Jul 05 04:43:07 masterbedroom volumio[1091]: status: 'Creating backup' Jul 05 04:43:07 masterbedroom volumio[1091]: } Jul 05 04:43:07 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:07 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:07 masterbedroom volumio[1091]: { Jul 05 04:43:07 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:07 masterbedroom volumio[1091]: eta: '5m', Jul 05 04:43:07 masterbedroom volumio[1091]: progress: 15, Jul 05 04:43:07 masterbedroom volumio[1091]: status: 'Creating backup' Jul 05 04:43:07 masterbedroom volumio[1091]: } Jul 05 04:43:08 masterbedroom volumio-remote-updater[652]: PROGRESS: 15, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:08 masterbedroom volumio-remote-updater[652]: PROGRESS: 16, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:08 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:08 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:08 masterbedroom volumio[1091]: { Jul 05 04:43:08 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:08 masterbedroom volumio[1091]: eta: '5m', Jul 05 04:43:08 masterbedroom volumio[1091]: progress: 16, Jul 05 04:43:08 masterbedroom volumio[1091]: status: 'Creating backup' Jul 05 04:43:08 masterbedroom volumio[1091]: } Jul 05 04:43:09 masterbedroom systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 04:43:09 masterbedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12815. Jul 05 04:43:09 masterbedroom systemd[1]: Stopped go-librespot Daemon. Jul 05 04:43:09 masterbedroom volumio[1091]: info: Initializing connection to go-librespot Websocket Jul 05 04:43:09 masterbedroom volumio[1091]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 04:43:09 masterbedroom systemd[1]: Started go-librespot Daemon. Jul 05 04:43:09 masterbedroom go-librespot[11930]: Librespot-go daemon starting... Jul 05 04:43:09 masterbedroom go-librespot[11930]: time="2024-07-05T04:43:09+01:00" level=info msg="generated new device id: 6388f954d53da96b40e0e8ceba11e90436915e89" Jul 05 04:43:09 masterbedroom go-librespot[11930]: time="2024-07-05T04:43:09+01:00" level=debug msg="stored credentials found for arbitrabbit" Jul 05 04:43:09 masterbedroom go-librespot[11930]: time="2024-07-05T04:43:09+01:00" level=debug msg="obtained new client token: AAALjc5/3n0BFhIluOQfVA6KJ1xotQiawhvcHAHoAp2rBnECf0CDoqTaMeZzsKFdSSteayX1EVCdw4zGIsV+OQ7O7bjgHF/cAdOIBt66dvz8BN7IPQB8bXNiKaLLfM2sNyGDfmOvjMtjpIZVbTdyBpw1V2SY//e5ni50/3aRLAqIQFxvefJ0x+Su8gYHlb4AzkDuX1IeuUCDCu6AfoNqNDds3AuVOhptmsm0HLI48gkj8pBtm7bsnwLKkTTI" Jul 05 04:43:09 masterbedroom go-librespot[11930]: time="2024-07-05T04:43:09+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 04:43:09 masterbedroom go-librespot[11930]: time="2024-07-05T04:43:09+01:00" level=debug msg="completed keyexchange" Jul 05 04:43:09 masterbedroom volumio-remote-updater[652]: PROGRESS: 16, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:09 masterbedroom volumio-remote-updater[652]: PROGRESS: 16, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:09 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:09 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:09 masterbedroom volumio[1091]: { Jul 05 04:43:09 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:09 masterbedroom volumio[1091]: eta: '5m', Jul 05 04:43:09 masterbedroom volumio[1091]: progress: 16, Jul 05 04:43:09 masterbedroom volumio[1091]: status: 'Creating backup' Jul 05 04:43:09 masterbedroom volumio[1091]: } Jul 05 04:43:09 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:09 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:09 masterbedroom volumio[1091]: { Jul 05 04:43:09 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:09 masterbedroom volumio[1091]: eta: '5m', Jul 05 04:43:09 masterbedroom volumio[1091]: progress: 16, Jul 05 04:43:09 masterbedroom volumio[1091]: status: 'Creating backup' Jul 05 04:43:09 masterbedroom volumio[1091]: } Jul 05 04:43:10 masterbedroom go-librespot[11930]: time="2024-07-05T04:43:10+01:00" level=debug msg="completed challenge" Jul 05 04:43:10 masterbedroom go-librespot[11930]: time="2024-07-05T04:43:10+01: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 04:43:10 masterbedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 04:43:10 masterbedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 04:43:10 masterbedroom volumio-remote-updater[652]: PROGRESS: 16, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:10 masterbedroom volumio-remote-updater[652]: PROGRESS: 17, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:10 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:10 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:10 masterbedroom volumio[1091]: { Jul 05 04:43:10 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:10 masterbedroom volumio[1091]: eta: '5m', Jul 05 04:43:10 masterbedroom volumio[1091]: progress: 17, Jul 05 04:43:10 masterbedroom volumio[1091]: status: 'Creating backup' Jul 05 04:43:10 masterbedroom volumio[1091]: } Jul 05 04:43:10 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:10 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:10 masterbedroom volumio[1091]: { Jul 05 04:43:10 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:10 masterbedroom volumio[1091]: eta: '5m', Jul 05 04:43:10 masterbedroom volumio[1091]: progress: 17, Jul 05 04:43:10 masterbedroom volumio[1091]: status: 'Creating backup' Jul 05 04:43:10 masterbedroom volumio[1091]: } Jul 05 04:43:11 masterbedroom volumio-remote-updater[652]: PROGRESS: 17, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:11 masterbedroom volumio-remote-updater[652]: PROGRESS: 18, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:11 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:11 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:11 masterbedroom volumio[1091]: { Jul 05 04:43:11 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:11 masterbedroom volumio[1091]: eta: '5m', Jul 05 04:43:11 masterbedroom volumio[1091]: progress: 18, Jul 05 04:43:11 masterbedroom volumio[1091]: status: 'Creating backup' Jul 05 04:43:11 masterbedroom volumio[1091]: } Jul 05 04:43:11 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:11 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:11 masterbedroom volumio[1091]: { Jul 05 04:43:11 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:11 masterbedroom volumio[1091]: eta: '5m', Jul 05 04:43:11 masterbedroom volumio[1091]: progress: 18, Jul 05 04:43:11 masterbedroom volumio[1091]: status: 'Creating backup' Jul 05 04:43:11 masterbedroom volumio[1091]: } Jul 05 04:43:12 masterbedroom volumio[1091]: info: Initializing connection to go-librespot Websocket Jul 05 04:43:12 masterbedroom volumio[1091]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 04:43:12 masterbedroom volumio-remote-updater[652]: PROGRESS: 18, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:12 masterbedroom volumio-remote-updater[652]: PROGRESS: 18, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:12 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:12 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:12 masterbedroom volumio[1091]: { Jul 05 04:43:12 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:12 masterbedroom volumio[1091]: eta: '5m', Jul 05 04:43:12 masterbedroom volumio[1091]: progress: 18, Jul 05 04:43:12 masterbedroom volumio[1091]: status: 'Creating backup' Jul 05 04:43:12 masterbedroom volumio[1091]: } Jul 05 04:43:13 masterbedroom systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 04:43:13 masterbedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12816. Jul 05 04:43:13 masterbedroom systemd[1]: Stopped go-librespot Daemon. Jul 05 04:43:13 masterbedroom systemd[1]: Started go-librespot Daemon. Jul 05 04:43:13 masterbedroom go-librespot[11988]: Librespot-go daemon starting... Jul 05 04:43:13 masterbedroom go-librespot[11988]: time="2024-07-05T04:43:13+01:00" level=info msg="generated new device id: 6aaf459fe43be4f30a2e695b6c76fd6f4d613192" Jul 05 04:43:13 masterbedroom go-librespot[11988]: time="2024-07-05T04:43:13+01:00" level=debug msg="stored credentials found for arbitrabbit" Jul 05 04:43:13 masterbedroom go-librespot[11988]: time="2024-07-05T04:43:13+01:00" level=debug msg="obtained new client token: AACOB2HClefTrtQFX1BOci2lmKqXVqpL295DrlxJVmxSqsh/dYY8ffVK6mhgWUstp8OYGHPwHCVM8AtTOg+UoONEC7G0VggDXeuxD9ErZxj/6VJWrKX0SZqzYSYdNBzREtbdcFN73Xy08LBd3aErCtN+zHgjpiYj6Mu+zMpck5s5FeVsRn4aKiH1sn1RTO7dMVI0j4w876I+V/GZYQFfDwSiu+R75lYwFoT8NiJJ3vcDkcC89HV1f5KJEELL" Jul 05 04:43:13 masterbedroom go-librespot[11988]: time="2024-07-05T04:43:13+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jul 05 04:43:13 masterbedroom go-librespot[11988]: time="2024-07-05T04:43:13+01:00" level=debug msg="completed keyexchange" Jul 05 04:43:13 masterbedroom volumio-remote-updater[652]: PROGRESS: 18, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:13 masterbedroom volumio-remote-updater[652]: PROGRESS: 19, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:13 masterbedroom volumio-remote-updater[652]: PROGRESS: 19, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:13 masterbedroom volumio-remote-updater[652]: PROGRESS: 19, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:13 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:13 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:13 masterbedroom volumio[1091]: { Jul 05 04:43:13 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:13 masterbedroom volumio[1091]: eta: '5m', Jul 05 04:43:13 masterbedroom volumio[1091]: progress: 19, Jul 05 04:43:13 masterbedroom volumio[1091]: status: 'Creating backup' Jul 05 04:43:13 masterbedroom volumio[1091]: } Jul 05 04:43:13 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:13 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:13 masterbedroom volumio[1091]: { Jul 05 04:43:13 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:13 masterbedroom volumio[1091]: eta: '5m', Jul 05 04:43:13 masterbedroom volumio[1091]: progress: 19, Jul 05 04:43:13 masterbedroom volumio[1091]: status: 'Creating backup' Jul 05 04:43:13 masterbedroom volumio[1091]: } Jul 05 04:43:13 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:13 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:13 masterbedroom volumio[1091]: { Jul 05 04:43:13 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:13 masterbedroom volumio[1091]: eta: '5m', Jul 05 04:43:13 masterbedroom volumio[1091]: progress: 19, Jul 05 04:43:13 masterbedroom volumio[1091]: status: 'Creating backup' Jul 05 04:43:13 masterbedroom volumio[1091]: } Jul 05 04:43:13 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:13 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:13 masterbedroom volumio[1091]: { Jul 05 04:43:13 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:13 masterbedroom volumio[1091]: eta: '5m', Jul 05 04:43:13 masterbedroom volumio[1091]: progress: 19, Jul 05 04:43:13 masterbedroom volumio[1091]: status: 'Creating backup' Jul 05 04:43:13 masterbedroom volumio[1091]: } Jul 05 04:43:14 masterbedroom go-librespot[11988]: time="2024-07-05T04:43:14+01:00" level=debug msg="completed challenge" Jul 05 04:43:14 masterbedroom go-librespot[11988]: time="2024-07-05T04:43:14+01: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 04:43:14 masterbedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 04:43:14 masterbedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 04:43:14 masterbedroom volumio-remote-updater[652]: PROGRESS: 19, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:14 masterbedroom volumio-remote-updater[652]: PROGRESS: 19, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:14 masterbedroom volumio-remote-updater[652]: PROGRESS: 19, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:14 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:14 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:14 masterbedroom volumio[1091]: { Jul 05 04:43:14 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:14 masterbedroom volumio[1091]: eta: '5m', Jul 05 04:43:14 masterbedroom volumio[1091]: progress: 19, Jul 05 04:43:14 masterbedroom volumio[1091]: status: 'Creating backup' Jul 05 04:43:14 masterbedroom volumio[1091]: } Jul 05 04:43:14 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:14 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:14 masterbedroom volumio[1091]: { Jul 05 04:43:14 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:14 masterbedroom volumio[1091]: eta: '5m', Jul 05 04:43:14 masterbedroom volumio[1091]: progress: 19, Jul 05 04:43:14 masterbedroom volumio[1091]: status: 'Creating backup' Jul 05 04:43:14 masterbedroom volumio[1091]: } Jul 05 04:43:15 masterbedroom volumio[1091]: info: Initializing connection to go-librespot Websocket Jul 05 04:43:15 masterbedroom volumio[1091]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 04:43:16 masterbedroom volumio-remote-updater[652]: PROGRESS: 19, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:16 masterbedroom volumio-remote-updater[652]: PROGRESS: 19, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:16 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:16 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:16 masterbedroom volumio[1091]: { Jul 05 04:43:16 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:16 masterbedroom volumio[1091]: eta: '5m', Jul 05 04:43:16 masterbedroom volumio[1091]: progress: 19, Jul 05 04:43:16 masterbedroom volumio[1091]: status: 'Creating backup' Jul 05 04:43:16 masterbedroom volumio[1091]: } Jul 05 04:43:17 masterbedroom systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 04:43:17 masterbedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12817. Jul 05 04:43:17 masterbedroom systemd[1]: Stopped go-librespot Daemon. Jul 05 04:43:17 masterbedroom systemd[1]: Started go-librespot Daemon. Jul 05 04:43:17 masterbedroom go-librespot[11997]: Librespot-go daemon starting... Jul 05 04:43:17 masterbedroom go-librespot[11997]: time="2024-07-05T04:43:17+01:00" level=info msg="generated new device id: 0c9379c0e460a56b9a9014f707cc1155f0d358ed" Jul 05 04:43:17 masterbedroom go-librespot[11997]: time="2024-07-05T04:43:17+01:00" level=debug msg="stored credentials found for arbitrabbit" Jul 05 04:43:17 masterbedroom go-librespot[11997]: time="2024-07-05T04:43:17+01:00" level=debug msg="obtained new client token: AAAgKDmgQ/6OAebrf4wyCD59rt0BdbCQScGtyFvSH8VQ3AMlEKUfcr3L08wyYLIK9Xrwc0+u/nzatz2T/LpgG/l2OvgF+wF8HDljjk603JPEEwP4cnH3iCbyoMdaS0rfg5M0x80oKPGI2CiIMWjvt+fMtuGLNfW7nxkRUyReHBvvSPsnQfI63BCOcAHqt/mX/kp8TpKqoozUJm5xbQtPGBoZOlof7UamzhzcViZUUnpfGbiDHGmdVYcvmBfP" Jul 05 04:43:17 masterbedroom volumio-remote-updater[652]: PROGRESS: 19, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:17 masterbedroom volumio-remote-updater[652]: PROGRESS: 20, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:17 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:17 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:17 masterbedroom volumio[1091]: { Jul 05 04:43:17 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:17 masterbedroom volumio[1091]: eta: '5m', Jul 05 04:43:17 masterbedroom volumio[1091]: progress: 20, Jul 05 04:43:17 masterbedroom volumio[1091]: status: 'Creating backup' Jul 05 04:43:17 masterbedroom volumio[1091]: } Jul 05 04:43:17 masterbedroom go-librespot[11997]: time="2024-07-05T04:43:17+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jul 05 04:43:18 masterbedroom volumio[1091]: info: Initializing connection to go-librespot Websocket Jul 05 04:43:18 masterbedroom go-librespot[11997]: time="2024-07-05T04:43:18+01:00" level=debug msg="new websocket client" Jul 05 04:43:18 masterbedroom volumio[1091]: info: Connection to go-librespot Websocket established Jul 05 04:43:18 masterbedroom volumio-remote-updater[652]: PROGRESS: 20, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:18 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:18 masterbedroom volumio-remote-updater[652]: PROGRESS: 21, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:18 masterbedroom volumio-remote-updater[652]: PROGRESS: 21, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:18 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:18 masterbedroom volumio[1091]: { Jul 05 04:43:18 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:18 masterbedroom volumio[1091]: eta: '5m', Jul 05 04:43:18 masterbedroom volumio[1091]: progress: 20, Jul 05 04:43:18 masterbedroom volumio[1091]: status: 'Creating backup' Jul 05 04:43:18 masterbedroom volumio[1091]: } Jul 05 04:43:18 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:18 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:18 masterbedroom volumio[1091]: { Jul 05 04:43:18 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:18 masterbedroom volumio[1091]: eta: '5m', Jul 05 04:43:18 masterbedroom volumio[1091]: progress: 21, Jul 05 04:43:18 masterbedroom volumio[1091]: status: 'Creating backup' Jul 05 04:43:18 masterbedroom volumio[1091]: } Jul 05 04:43:19 masterbedroom volumio-remote-updater[652]: PROGRESS: 21, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:19 masterbedroom volumio-remote-updater[652]: PROGRESS: 22, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:19 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:19 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:19 masterbedroom volumio[1091]: { Jul 05 04:43:19 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:19 masterbedroom volumio[1091]: eta: '5m', Jul 05 04:43:19 masterbedroom volumio[1091]: progress: 22, Jul 05 04:43:19 masterbedroom volumio[1091]: status: 'Creating backup' Jul 05 04:43:19 masterbedroom volumio[1091]: } Jul 05 04:43:19 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:19 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:19 masterbedroom volumio[1091]: { Jul 05 04:43:19 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:19 masterbedroom volumio[1091]: eta: '5m', Jul 05 04:43:19 masterbedroom volumio[1091]: progress: 22, Jul 05 04:43:19 masterbedroom volumio[1091]: status: 'Creating backup' Jul 05 04:43:19 masterbedroom volumio[1091]: } Jul 05 04:43:21 masterbedroom volumio[1091]: info: Getting Spotify volume Jul 05 04:43:21 masterbedroom volumio[1091]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Jul 05 04:43:21 masterbedroom volumio[1091]: info: CoreCommandRouter::volumioGetState Jul 05 04:43:21 masterbedroom volumio[1091]: SPOTIFY: RECEIVED VOLUMIO VOLUME 9 Jul 05 04:43:21 masterbedroom volumio-remote-updater[652]: PROGRESS: 22, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:21 masterbedroom volumio-remote-updater[652]: PROGRESS: 22, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:21 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:21 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:21 masterbedroom volumio[1091]: { Jul 05 04:43:21 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:21 masterbedroom volumio[1091]: eta: '5m', Jul 05 04:43:21 masterbedroom volumio[1091]: progress: 22, Jul 05 04:43:21 masterbedroom volumio[1091]: status: 'Creating backup' Jul 05 04:43:21 masterbedroom volumio[1091]: } Jul 05 04:43:21 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:21 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:21 masterbedroom volumio[1091]: { Jul 05 04:43:21 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:21 masterbedroom volumio[1091]: eta: '5m', Jul 05 04:43:21 masterbedroom volumio[1091]: progress: 22, Jul 05 04:43:21 masterbedroom volumio[1091]: status: 'Creating backup' Jul 05 04:43:21 masterbedroom volumio[1091]: } Jul 05 04:43:22 masterbedroom volumio-remote-updater[652]: PROGRESS: 22, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:22 masterbedroom volumio-remote-updater[652]: PROGRESS: 23, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:22 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:22 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:22 masterbedroom volumio[1091]: { Jul 05 04:43:22 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:22 masterbedroom volumio[1091]: eta: '5m', Jul 05 04:43:22 masterbedroom volumio[1091]: progress: 23, Jul 05 04:43:22 masterbedroom volumio[1091]: status: 'Creating backup' Jul 05 04:43:22 masterbedroom volumio[1091]: } Jul 05 04:43:22 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:22 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:22 masterbedroom volumio[1091]: { Jul 05 04:43:22 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:22 masterbedroom volumio[1091]: eta: '5m', Jul 05 04:43:22 masterbedroom volumio[1091]: progress: 23, Jul 05 04:43:22 masterbedroom volumio[1091]: status: 'Creating backup' Jul 05 04:43:22 masterbedroom volumio[1091]: } Jul 05 04:43:22 masterbedroom go-librespot[11997]: time="2024-07-05T04:43:22+01:00" level=debug msg="completed keyexchange" Jul 05 04:43:22 masterbedroom volumio-remote-updater[652]: PROGRESS: 23, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:22 masterbedroom volumio-remote-updater[652]: PROGRESS: 25, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:22 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:22 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:22 masterbedroom volumio[1091]: { Jul 05 04:43:22 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:22 masterbedroom volumio[1091]: eta: '5m', Jul 05 04:43:22 masterbedroom volumio[1091]: progress: 25, Jul 05 04:43:22 masterbedroom volumio[1091]: status: 'Creating backup' Jul 05 04:43:22 masterbedroom volumio[1091]: } Jul 05 04:43:22 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:22 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:22 masterbedroom volumio[1091]: { Jul 05 04:43:22 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:22 masterbedroom volumio[1091]: eta: '5m', Jul 05 04:43:22 masterbedroom volumio[1091]: progress: 25, Jul 05 04:43:22 masterbedroom volumio[1091]: status: 'Creating backup' Jul 05 04:43:22 masterbedroom volumio[1091]: } Jul 05 04:43:23 masterbedroom go-librespot[11997]: time="2024-07-05T04:43:23+01:00" level=debug msg="completed challenge" Jul 05 04:43:23 masterbedroom go-librespot[11997]: time="2024-07-05T04:43:23+01: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 04:43:23 masterbedroom volumio[1091]: (node:1091) UnhandledPromiseRejectionWarning: Error: socket hang up Jul 05 04:43:23 masterbedroom volumio[1091]: at connResetException (internal/errors.js:607:14) Jul 05 04:43:23 masterbedroom volumio[1091]: at Socket.socketOnEnd (_http_client.js:493:23) Jul 05 04:43:23 masterbedroom volumio[1091]: at Socket.emit (events.js:327:22) Jul 05 04:43:23 masterbedroom volumio[1091]: at endReadableNT (internal/streams/readable.js:1327:12) Jul 05 04:43:23 masterbedroom volumio[1091]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Jul 05 04:43:23 masterbedroom volumio[1091]: (node:1091) 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: 999) Jul 05 04:43:23 masterbedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 04:43:23 masterbedroom volumio[1091]: info: Connection to go-librespot Websocket closed Jul 05 04:43:23 masterbedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 04:43:25 masterbedroom volumio-remote-updater[652]: PROGRESS: 25, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:25 masterbedroom volumio-remote-updater[652]: PROGRESS: 25, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:25 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:25 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:25 masterbedroom volumio[1091]: { Jul 05 04:43:25 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:25 masterbedroom volumio[1091]: eta: '5m', Jul 05 04:43:25 masterbedroom volumio[1091]: progress: 25, Jul 05 04:43:25 masterbedroom volumio[1091]: status: 'Creating backup' Jul 05 04:43:25 masterbedroom volumio[1091]: } Jul 05 04:43:25 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:25 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:25 masterbedroom volumio[1091]: { Jul 05 04:43:25 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:25 masterbedroom volumio[1091]: eta: '5m', Jul 05 04:43:25 masterbedroom volumio[1091]: progress: 25, Jul 05 04:43:25 masterbedroom volumio[1091]: status: 'Creating backup' Jul 05 04:43:25 masterbedroom volumio[1091]: } Jul 05 04:43:25 masterbedroom volumio-remote-updater[652]: PROGRESS: 25, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:25 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:25 masterbedroom volumio-remote-updater[652]: PROGRESS: 25, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:25 masterbedroom volumio-remote-updater[652]: PROGRESS: 25, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:25 masterbedroom volumio-remote-updater[652]: PROGRESS: 25, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:25 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:25 masterbedroom volumio[1091]: { Jul 05 04:43:25 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:25 masterbedroom volumio[1091]: eta: '5m', Jul 05 04:43:25 masterbedroom volumio[1091]: progress: 25, Jul 05 04:43:25 masterbedroom volumio[1091]: status: 'Creating backup' Jul 05 04:43:25 masterbedroom volumio[1091]: } Jul 05 04:43:25 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:25 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:25 masterbedroom volumio[1091]: { Jul 05 04:43:25 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:25 masterbedroom volumio[1091]: eta: '5m', Jul 05 04:43:25 masterbedroom volumio[1091]: progress: 25, Jul 05 04:43:25 masterbedroom volumio[1091]: status: 'Creating backup' Jul 05 04:43:25 masterbedroom volumio[1091]: } Jul 05 04:43:25 masterbedroom volumio-remote-updater[652]: PROGRESS: 25, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:25 masterbedroom volumio-remote-updater[652]: PROGRESS: 30, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:25 masterbedroom volumio-remote-updater[652]: PROGRESS: 30, STATUS: "Creating backup", ETA: "5m" Jul 05 04:43:25 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:25 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:25 masterbedroom volumio[1091]: { Jul 05 04:43:25 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:25 masterbedroom volumio[1091]: eta: '5m', Jul 05 04:43:25 masterbedroom volumio[1091]: progress: 30, Jul 05 04:43:25 masterbedroom volumio[1091]: status: 'Creating backup' Jul 05 04:43:25 masterbedroom volumio[1091]: } Jul 05 04:43:25 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:25 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:25 masterbedroom volumio[1091]: { Jul 05 04:43:25 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:25 masterbedroom volumio[1091]: eta: '5m', Jul 05 04:43:25 masterbedroom volumio[1091]: progress: 30, Jul 05 04:43:25 masterbedroom volumio[1091]: status: 'Creating backup' Jul 05 04:43:25 masterbedroom volumio[1091]: } Jul 05 04:43:26 masterbedroom volumio[1091]: info: Initializing connection to go-librespot Websocket Jul 05 04:43:26 masterbedroom volumio[1091]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 04:43:26 masterbedroom systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 04:43:26 masterbedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12818. Jul 05 04:43:26 masterbedroom systemd[1]: Stopped go-librespot Daemon. Jul 05 04:43:26 masterbedroom systemd[1]: Started go-librespot Daemon. Jul 05 04:43:26 masterbedroom go-librespot[12013]: Librespot-go daemon starting... Jul 05 04:43:26 masterbedroom go-librespot[12013]: time="2024-07-05T04:43:26+01:00" level=info msg="generated new device id: ae28e2eac2ffd828fe051c2d76c881f95071ab25" Jul 05 04:43:26 masterbedroom go-librespot[12013]: time="2024-07-05T04:43:26+01:00" level=debug msg="stored credentials found for arbitrabbit" Jul 05 04:43:26 masterbedroom go-librespot[12013]: time="2024-07-05T04:43:26+01:00" level=debug msg="obtained new client token: AADH6PWHrF+VHPOH3LKQ1BHAxPGfwmZScSCwhN9zyf64YRgJ5gEwAOk/qtX/4kNE1FCzebO6+F13grzSgemNOkVpzGzJVvCuDIHo441X+BWYnl0QRBxFlD5mR3STAYkHZPYvc2aCLINTekx0lP94HX/oa1XHudj7SzTxjCW0BsJaxOdbMwwQJRsdTvfxa51SKzD7e4s8ElksJh8uGP7uUTpTG8QoGDZOxwSdCsAqIfS3aT5Gs0U3+2xwqKX7" Jul 05 04:43:26 masterbedroom go-librespot[12013]: time="2024-07-05T04:43:26+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 04:43:26 masterbedroom go-librespot[12013]: time="2024-07-05T04:43:26+01:00" level=debug msg="completed keyexchange" Jul 05 04:43:27 masterbedroom go-librespot[12013]: time="2024-07-05T04:43:27+01:00" level=debug msg="completed challenge" Jul 05 04:43:27 masterbedroom go-librespot[12013]: time="2024-07-05T04:43:27+01: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 04:43:27 masterbedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 04:43:27 masterbedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 04:43:27 masterbedroom volumio-remote-updater[652]: PROGRESS: 30, STATUS: "Downloading new update", ETA: "4m" Jul 05 04:43:27 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:27 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:27 masterbedroom volumio[1091]: { Jul 05 04:43:27 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:27 masterbedroom volumio[1091]: eta: '4m', Jul 05 04:43:27 masterbedroom volumio[1091]: progress: 30, Jul 05 04:43:27 masterbedroom volumio[1091]: status: 'Downloading new update' Jul 05 04:43:27 masterbedroom volumio[1091]: } Jul 05 04:43:29 masterbedroom volumio[1091]: info: Initializing connection to go-librespot Websocket Jul 05 04:43:29 masterbedroom volumio[1091]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 04:43:30 masterbedroom systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 04:43:30 masterbedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12819. Jul 05 04:43:30 masterbedroom systemd[1]: Stopped go-librespot Daemon. Jul 05 04:43:30 masterbedroom systemd[1]: Started go-librespot Daemon. Jul 05 04:43:30 masterbedroom go-librespot[12041]: Librespot-go daemon starting... Jul 05 04:43:30 masterbedroom go-librespot[12041]: time="2024-07-05T04:43:30+01:00" level=info msg="generated new device id: e3881df2671e6a89494ee64d056a94fc60b3c088" Jul 05 04:43:30 masterbedroom go-librespot[12041]: time="2024-07-05T04:43:30+01:00" level=debug msg="stored credentials found for arbitrabbit" Jul 05 04:43:30 masterbedroom go-librespot[12041]: time="2024-07-05T04:43:30+01:00" level=debug msg="obtained new client token: AABTlBSWehgrbRd3t3sSdRwm/70wrKlB/C9SWhk1x+QK1jW90tUaDGgALcADGI006e96chdfXiR9x+MJznYrUbntidvSvDnNp9mfsCZM2ByLfP6vcgQCIG8Tgwbmp/7EqVNpg7/uiYTfWgE4pqNRKl9HRXLY9/JZD8drCcXchJoILejuBnEFCC8UL90InQpkma+6WAdiIdBzvDYnpiY0jA4jlTiX4DPHqaUmBYW7uxF2LFUEENbq+ygQWzRB" Jul 05 04:43:30 masterbedroom go-librespot[12041]: time="2024-07-05T04:43:30+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jul 05 04:43:30 masterbedroom go-librespot[12041]: time="2024-07-05T04:43:30+01:00" level=debug msg="completed keyexchange" Jul 05 04:43:31 masterbedroom go-librespot[12041]: time="2024-07-05T04:43:31+01:00" level=debug msg="completed challenge" Jul 05 04:43:31 masterbedroom go-librespot[12041]: time="2024-07-05T04:43:31+01: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 04:43:31 masterbedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 04:43:31 masterbedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 04:43:32 masterbedroom volumio[1091]: info: Initializing connection to go-librespot Websocket Jul 05 04:43:32 masterbedroom volumio[1091]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 04:43:34 masterbedroom systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 04:43:34 masterbedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12820. Jul 05 04:43:34 masterbedroom systemd[1]: Stopped go-librespot Daemon. Jul 05 04:43:34 masterbedroom systemd[1]: Started go-librespot Daemon. Jul 05 04:43:34 masterbedroom go-librespot[12050]: Librespot-go daemon starting... Jul 05 04:43:34 masterbedroom go-librespot[12050]: time="2024-07-05T04:43:34+01:00" level=info msg="generated new device id: a0fcfe45ffd0e2b519652d969143e51d2513563c" Jul 05 04:43:34 masterbedroom go-librespot[12050]: time="2024-07-05T04:43:34+01:00" level=debug msg="stored credentials found for arbitrabbit" Jul 05 04:43:34 masterbedroom go-librespot[12050]: time="2024-07-05T04:43:34+01:00" level=debug msg="obtained new client token: AAAN9S6BpH07f4u2+KmPqzpSn359P7EdkKMfk8WvAiURLn0buSn4OkBJfNe2GASvihQl/hmVPbZROi7CXn8X8yGaZj+w6AT8kFNJlCKJ3T7I8Su+bPOE0FnfcDghSnG1aPIXfLLuU2fo8RRrzN4lpqeHHoqDviMYArq+RFUGqXcBsPqro1qGkO41HVHgdY38vqWt4tcLN4WwsDISZWn6XQhdnBJO22DuylMEwVbm6WI8mUBhnn+mSct+xsmS" Jul 05 04:43:34 masterbedroom go-librespot[12050]: time="2024-07-05T04:43:34+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jul 05 04:43:34 masterbedroom go-librespot[12050]: time="2024-07-05T04:43:34+01:00" level=debug msg="completed keyexchange" Jul 05 04:43:35 masterbedroom go-librespot[12050]: time="2024-07-05T04:43:35+01:00" level=debug msg="completed challenge" Jul 05 04:43:35 masterbedroom go-librespot[12050]: time="2024-07-05T04:43:35+01: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 04:43:35 masterbedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 04:43:35 masterbedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 04:43:35 masterbedroom volumio[1091]: info: Initializing connection to go-librespot Websocket Jul 05 04:43:35 masterbedroom volumio[1091]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 04:43:38 masterbedroom volumio[1091]: info: Initializing connection to go-librespot Websocket Jul 05 04:43:38 masterbedroom volumio[1091]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 04:43:38 masterbedroom systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 04:43:38 masterbedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12821. Jul 05 04:43:38 masterbedroom systemd[1]: Stopped go-librespot Daemon. Jul 05 04:43:38 masterbedroom systemd[1]: Started go-librespot Daemon. Jul 05 04:43:38 masterbedroom go-librespot[12059]: Librespot-go daemon starting... Jul 05 04:43:38 masterbedroom go-librespot[12059]: time="2024-07-05T04:43:38+01:00" level=info msg="generated new device id: cd449fef9e5a8fc7a740c1853a07a1ec4bada3c7" Jul 05 04:43:38 masterbedroom go-librespot[12059]: time="2024-07-05T04:43:38+01:00" level=debug msg="stored credentials found for arbitrabbit" Jul 05 04:43:38 masterbedroom go-librespot[12059]: time="2024-07-05T04:43:38+01:00" level=debug msg="obtained new client token: AAC1sV6TkLg/tFDMHBeGlElGTLrGq1hMPMvcOP7ShKs6V8wvfou5cTfcxHMpQ9KRDLf/1yobcAqetklRiGJvIuO5WpoojtRh7QKjeoRDFB5h2N0+oTOHo/GRaQx152Iy5EIqrJyxwWZTVSVaUlJi+6FILAa7NTdd7r8VaJKkZRjTBKYk3auDrgtrabNLeidhK0qlEEVCzxY8cj8eZfb3/4Gm7EcccJJWFce0e/XCd1Fj0+cZGlyEqqCqGPjy" Jul 05 04:43:38 masterbedroom go-librespot[12059]: time="2024-07-05T04:43:38+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jul 05 04:43:38 masterbedroom go-librespot[12059]: time="2024-07-05T04:43:38+01:00" level=debug msg="completed keyexchange" Jul 05 04:43:39 masterbedroom go-librespot[12059]: time="2024-07-05T04:43:39+01:00" level=debug msg="completed challenge" Jul 05 04:43:39 masterbedroom go-librespot[12059]: time="2024-07-05T04:43:39+01: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 04:43:39 masterbedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 04:43:39 masterbedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 04:43:41 masterbedroom volumio[1091]: info: Initializing connection to go-librespot Websocket Jul 05 04:43:41 masterbedroom volumio[1091]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 04:43:42 masterbedroom systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 04:43:42 masterbedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12822. Jul 05 04:43:42 masterbedroom systemd[1]: Stopped go-librespot Daemon. Jul 05 04:43:42 masterbedroom systemd[1]: Started go-librespot Daemon. Jul 05 04:43:42 masterbedroom go-librespot[12067]: Librespot-go daemon starting... Jul 05 04:43:42 masterbedroom go-librespot[12067]: time="2024-07-05T04:43:42+01:00" level=info msg="generated new device id: 0db33b1b4549cbd5903f10c107774fe292d3e7fa" Jul 05 04:43:42 masterbedroom go-librespot[12067]: time="2024-07-05T04:43:42+01:00" level=debug msg="stored credentials found for arbitrabbit" Jul 05 04:43:42 masterbedroom go-librespot[12067]: time="2024-07-05T04:43:42+01:00" level=debug msg="obtained new client token: AAApTK55h5OF7oEm0BoEOi9I4kcG5+/Ygtun2knRybM5wgF0XO0b675I5vEXYg2GYVE8WjKFlGRiyVadglH4OG0/RFgXv9Pd3aCHta+bHgTtoARKRifP/zrJPU2Vhvf8P1k6luQQ+cETguCfapK3J0NaS6OoC5gjFHuBR6Y630nWOyenw2zCNdeZ9o6UiYA/CwBbol1BoECye1M1iiTI4YVU2Jz5AD4rI7jwT8qFTdiPM/L16fcTpCfdkIz/" Jul 05 04:43:42 masterbedroom go-librespot[12067]: time="2024-07-05T04:43:42+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jul 05 04:43:42 masterbedroom go-librespot[12067]: time="2024-07-05T04:43:42+01:00" level=debug msg="completed keyexchange" Jul 05 04:43:43 masterbedroom go-librespot[12067]: time="2024-07-05T04:43:43+01:00" level=debug msg="completed challenge" Jul 05 04:43:43 masterbedroom go-librespot[12067]: time="2024-07-05T04:43:43+01: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 04:43:43 masterbedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 04:43:43 masterbedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 04:43:44 masterbedroom volumio[1091]: info: Initializing connection to go-librespot Websocket Jul 05 04:43:44 masterbedroom volumio[1091]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 04:43:46 masterbedroom systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 04:43:46 masterbedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12823. Jul 05 04:43:46 masterbedroom systemd[1]: Stopped go-librespot Daemon. Jul 05 04:43:46 masterbedroom systemd[1]: Started go-librespot Daemon. Jul 05 04:43:46 masterbedroom go-librespot[12075]: Librespot-go daemon starting... Jul 05 04:43:46 masterbedroom go-librespot[12075]: time="2024-07-05T04:43:46+01:00" level=info msg="generated new device id: 981c5a3ee54c301e3e76f75d8ead2aad887638aa" Jul 05 04:43:46 masterbedroom go-librespot[12075]: time="2024-07-05T04:43:46+01:00" level=debug msg="stored credentials found for arbitrabbit" Jul 05 04:43:46 masterbedroom go-librespot[12075]: time="2024-07-05T04:43:46+01:00" level=debug msg="obtained new client token: AAB4b6nvU+wcaOIaq2xntp6Yi8YhxSXUDro/zz5zvIOh0rOQ/Fe4Gl0MgpjZovuCjM7EIKsSUyuM34yBmcRwF73v+j/d+nL3tAxhcvo4e0rrjgKO5AgWF7T3MYgjwpGjujHz4KJ7U3+IbUyWGbcL4ButwTSZoZe5S0GlJHHc3b2Z2fxvMm+Sk75pP7FP7/puIuElFbaLKtgC9mfdKQUJGJPKEsdvyy1RvLj1LRr3VeVw7J0/lRO9pjbqrLI0" Jul 05 04:43:46 masterbedroom go-librespot[12075]: time="2024-07-05T04:43:46+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jul 05 04:43:46 masterbedroom go-librespot[12075]: time="2024-07-05T04:43:46+01:00" level=debug msg="completed keyexchange" Jul 05 04:43:47 masterbedroom go-librespot[12075]: time="2024-07-05T04:43:47+01:00" level=debug msg="completed challenge" Jul 05 04:43:47 masterbedroom go-librespot[12075]: time="2024-07-05T04:43:47+01: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 04:43:47 masterbedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 04:43:47 masterbedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 04:43:47 masterbedroom volumio[1091]: info: Initializing connection to go-librespot Websocket Jul 05 04:43:47 masterbedroom volumio[1091]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 04:43:47 masterbedroom volumio-remote-updater[652]: zsync done Jul 05 04:43:48 masterbedroom volumio-remote-updater[652]: PROGRESS: 80, STATUS: "Downloading new update", ETA: "2m" Jul 05 04:43:48 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:48 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:48 masterbedroom volumio[1091]: { Jul 05 04:43:48 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:48 masterbedroom volumio[1091]: eta: '2m', Jul 05 04:43:48 masterbedroom volumio[1091]: progress: 80, Jul 05 04:43:48 masterbedroom volumio[1091]: status: 'Downloading new update' Jul 05 04:43:48 masterbedroom volumio[1091]: } Jul 05 04:43:50 masterbedroom volumio[1091]: info: Initializing connection to go-librespot Websocket Jul 05 04:43:50 masterbedroom volumio[1091]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 04:43:50 masterbedroom systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 04:43:50 masterbedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12824. Jul 05 04:43:50 masterbedroom systemd[1]: Stopped go-librespot Daemon. Jul 05 04:43:50 masterbedroom systemd[1]: Started go-librespot Daemon. Jul 05 04:43:50 masterbedroom go-librespot[12089]: Librespot-go daemon starting... Jul 05 04:43:50 masterbedroom go-librespot[12089]: time="2024-07-05T04:43:50+01:00" level=info msg="generated new device id: e618da622904300bab3cefd73e4bd6a9ef70bae4" Jul 05 04:43:50 masterbedroom go-librespot[12089]: time="2024-07-05T04:43:50+01:00" level=debug msg="stored credentials found for arbitrabbit" Jul 05 04:43:50 masterbedroom go-librespot[12089]: time="2024-07-05T04:43:50+01:00" level=debug msg="obtained new client token: AAB2M+r83TNAyH95U+Jgo10LrW7Euoj17+O5DNaa4wAd0Bgi9tHynbRhbQ1D3XOXgDpH7BvLGNnNu0OVciusBwj99jPI7nqOiTV/mzcrxVz0XLc08A+UIaYET4jQwAMwLFi0dJBQk1QkDRvsEr1wVGD26Yj2CuBgMeP+Rfc4fMGz4DESAT+4BiFcN4HiVofxNfz9rfz+0zqU/uWnMySs+XmL+Mw3vDXEzZ4HGc0Oo/zheuryzI6CxUbZrw0g" Jul 05 04:43:50 masterbedroom go-librespot[12089]: time="2024-07-05T04:43:50+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jul 05 04:43:50 masterbedroom go-librespot[12089]: time="2024-07-05T04:43:50+01:00" level=debug msg="completed keyexchange" Jul 05 04:43:50 masterbedroom volumio-remote-updater[652]: zsync done Jul 05 04:43:51 masterbedroom go-librespot[12089]: time="2024-07-05T04:43:51+01:00" level=debug msg="completed challenge" Jul 05 04:43:51 masterbedroom go-librespot[12089]: time="2024-07-05T04:43:51+01: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 04:43:51 masterbedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 04:43:51 masterbedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 04:43:51 masterbedroom volumio-remote-updater[652]: PROGRESS: 90, STATUS: "Cleaning old files", ETA: "1m" Jul 05 04:43:51 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:51 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:51 masterbedroom volumio[1091]: { Jul 05 04:43:51 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:51 masterbedroom volumio[1091]: eta: '1m', Jul 05 04:43:51 masterbedroom volumio[1091]: progress: 90, Jul 05 04:43:51 masterbedroom volumio[1091]: status: 'Cleaning old files' Jul 05 04:43:51 masterbedroom volumio[1091]: } Jul 05 04:43:51 masterbedroom volumio-remote-updater[652]: /bin/cp: cannot stat '/data/volumio_factory.sqsh': No such file or directory Jul 05 04:43:51 masterbedroom volumio-remote-updater[652]: /bin/rm: cannot remove '/data/volumio_factory.sqsh': No such file or directory Jul 05 04:43:51 masterbedroom volumio-remote-updater[652]: PROGRESS: 95, STATUS: "Finalizing update", ETA: "30s" Jul 05 04:43:51 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:51 masterbedroom volumio[1091]: updateProgress Jul 05 04:43:51 masterbedroom volumio[1091]: { Jul 05 04:43:51 masterbedroom volumio[1091]: downloadSpeed: '', Jul 05 04:43:51 masterbedroom volumio[1091]: eta: '30s', Jul 05 04:43:51 masterbedroom volumio[1091]: progress: 95, Jul 05 04:43:51 masterbedroom volumio[1091]: status: 'Finalizing update' Jul 05 04:43:51 masterbedroom volumio[1091]: } Jul 05 04:43:51 masterbedroom volumio-remote-updater[652]: PROGRESS: 100, STATUS: "success", MESSAGE: "Successfully updated to \"3.735\" version. System restart required." Jul 05 04:43:51 masterbedroom volumio-remote-updater[652]: Test mode enabled Jul 05 04:43:51 masterbedroom volumio-remote-updater[652]: No alpha test mode Jul 05 04:43:51 masterbedroom volumio-remote-updater[652]: [2024-07-05 04:43:51] [disconnect] Disconnect close local:[1000] remote:[1000] Jul 05 04:43:51 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:51 masterbedroom volumio-remote-updater[652]: [2024-07-05 04:43:51] [info] asio async_write error: system:32 (Broken pipe) Jul 05 04:43:51 masterbedroom volumio-remote-updater[652]: [2024-07-05 04:43:51] [fatal] handle_write_frame error: websocketpp.transport:2 (Underlying Transport Error) Jul 05 04:43:51 masterbedroom volumio[1091]: updateReady Jul 05 04:43:51 masterbedroom volumio[1091]: { Jul 05 04:43:51 masterbedroom volumio[1091]: changeLogLink: 'http://volumio.org', Jul 05 04:43:51 masterbedroom volumio[1091]: description: '

FIXES

\n' + Jul 05 04:43:51 masterbedroom volumio[1091]: '\n' + Jul 05 04:43:51 masterbedroom volumio[1091]: '

NEW ADDITIONS

\n' + Jul 05 04:43:51 masterbedroom volumio[1091]: '\n', Jul 05 04:43:51 masterbedroom volumio[1091]: title: 'Update v3.735', Jul 05 04:43:51 masterbedroom volumio[1091]: updateavailable: true Jul 05 04:43:51 masterbedroom volumio[1091]: } Jul 05 04:43:51 masterbedroom systemd[1]: volumio-remote-updater.service: Succeeded. Jul 05 04:43:52 masterbedroom systemd[1]: volumio-remote-updater.service: Service RestartSec=100ms expired, scheduling restart. Jul 05 04:43:52 masterbedroom systemd[1]: volumio-remote-updater.service: Scheduled restart job, restart counter is at 1. Jul 05 04:43:52 masterbedroom systemd[1]: Stopped volumio-remote-updater.service. Jul 05 04:43:52 masterbedroom systemd[1]: Started volumio-remote-updater.service. Jul 05 04:43:52 masterbedroom volumio-remote-updater[12112]: Error: No active session Jul 05 04:43:52 masterbedroom volumio-remote-updater[12112]: [2024-07-05 04:43:52] [connect] Successful connection Jul 05 04:43:52 masterbedroom volumio-remote-updater[12112]: [2024-07-05 04:43:52] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1720151032 101 Jul 05 04:43:52 masterbedroom volumio[1091]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 7 Jul 05 04:43:52 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:53 masterbedroom volumio[1091]: info: Initializing connection to go-librespot Websocket Jul 05 04:43:53 masterbedroom volumio[1091]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 04:43:53 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:54 masterbedroom systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 04:43:54 masterbedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12825. Jul 05 04:43:54 masterbedroom systemd[1]: Stopped go-librespot Daemon. Jul 05 04:43:54 masterbedroom systemd[1]: Started go-librespot Daemon. Jul 05 04:43:54 masterbedroom go-librespot[12115]: Librespot-go daemon starting... Jul 05 04:43:54 masterbedroom go-librespot[12115]: time="2024-07-05T04:43:54+01:00" level=info msg="generated new device id: 70bf6155a446fda9704693abffe5fbfdb40f5870" Jul 05 04:43:54 masterbedroom go-librespot[12115]: time="2024-07-05T04:43:54+01:00" level=debug msg="stored credentials found for arbitrabbit" Jul 05 04:43:54 masterbedroom go-librespot[12115]: time="2024-07-05T04:43:54+01:00" level=debug msg="obtained new client token: AADPaj+Aqz6ZuOpkdSOvR8Z/uf79htu48zF9t845GEaPbgATo85kS8vbCWWjfI0yF/sfcudiq9/jUj/rN063CXF3NDOkMLXSaMTfufkHsU2Ovb5ZHzxcg2gF8EXh4Dwf5yAFl+TpO4usAhKiNRwFz2r6m8NRieyTAzOa1sm0eqIbZakalh8orU9QQcvKmoNKj5XcE0tu991ISWtsXgSMJxOlz/uis7fY/qGsPzNfqzcUnkasbcIh5B+Ozpww" Jul 05 04:43:54 masterbedroom go-librespot[12115]: time="2024-07-05T04:43:54+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 04:43:54 masterbedroom go-librespot[12115]: time="2024-07-05T04:43:54+01:00" level=debug msg="completed keyexchange" Jul 05 04:43:54 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:55 masterbedroom go-librespot[12115]: time="2024-07-05T04:43:55+01:00" level=debug msg="completed challenge" Jul 05 04:43:55 masterbedroom go-librespot[12115]: time="2024-07-05T04:43:55+01: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 04:43:55 masterbedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 04:43:55 masterbedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 04:43:55 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:56 masterbedroom volumio[1091]: info: Initializing connection to go-librespot Websocket Jul 05 04:43:56 masterbedroom volumio[1091]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 04:43:56 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:57 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:58 masterbedroom systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 04:43:58 masterbedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12826. Jul 05 04:43:58 masterbedroom systemd[1]: Stopped go-librespot Daemon. Jul 05 04:43:58 masterbedroom systemd[1]: Started go-librespot Daemon. Jul 05 04:43:58 masterbedroom go-librespot[12124]: Librespot-go daemon starting... Jul 05 04:43:58 masterbedroom go-librespot[12124]: time="2024-07-05T04:43:58+01:00" level=info msg="generated new device id: 025c9bdbef5131dc6d8a1bb55d92c43e8914dddf" Jul 05 04:43:58 masterbedroom go-librespot[12124]: time="2024-07-05T04:43:58+01:00" level=debug msg="stored credentials found for arbitrabbit" Jul 05 04:43:58 masterbedroom go-librespot[12124]: time="2024-07-05T04:43:58+01:00" level=debug msg="obtained new client token: AAChac2unshbYUkFcmubwmGqG113iRV8ryOW51Jxsy6b1TZxPyX++EgxjPCmmOR0F3lERmg/qUCKPAKHz+LVkLyfig0N8dZn8xj+mOCAjGxIwpSAB6BOTm7sZ9hJi7E+3wAZVcezayWmHZ8CDQ7m0zYk7qbXs0CjLjQY5Pfx3XbaD/CMN+cFLJc+Xp8qNseyddeABy4lKHTPABQZi9F7uEgr8rZeoUGLFtPxYqT73zbW/X3tjyXUgBdAPI+K" Jul 05 04:43:58 masterbedroom go-librespot[12124]: time="2024-07-05T04:43:58+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 05 04:43:58 masterbedroom go-librespot[12124]: time="2024-07-05T04:43:58+01:00" level=debug msg="completed keyexchange" Jul 05 04:43:58 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:43:59 masterbedroom go-librespot[12124]: time="2024-07-05T04:43:59+01:00" level=debug msg="completed challenge" Jul 05 04:43:59 masterbedroom go-librespot[12124]: time="2024-07-05T04:43:59+01: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 04:43:59 masterbedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 04:43:59 masterbedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 04:43:59 masterbedroom volumio[1091]: info: Initializing connection to go-librespot Websocket Jul 05 04:43:59 masterbedroom volumio[1091]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 04:43:59 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:44:00 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:44:01 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:44:02 masterbedroom volumio[1091]: info: Initializing connection to go-librespot Websocket Jul 05 04:44:02 masterbedroom volumio[1091]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 04:44:02 masterbedroom systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 04:44:02 masterbedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12827. Jul 05 04:44:02 masterbedroom systemd[1]: Stopped go-librespot Daemon. Jul 05 04:44:02 masterbedroom systemd[1]: Started go-librespot Daemon. Jul 05 04:44:02 masterbedroom go-librespot[12132]: Librespot-go daemon starting... Jul 05 04:44:02 masterbedroom go-librespot[12132]: time="2024-07-05T04:44:02+01:00" level=info msg="generated new device id: 8b4e23118eb103e99961871f5515d788e7d55ad7" Jul 05 04:44:02 masterbedroom go-librespot[12132]: time="2024-07-05T04:44:02+01:00" level=debug msg="stored credentials found for arbitrabbit" Jul 05 04:44:02 masterbedroom go-librespot[12132]: time="2024-07-05T04:44:02+01:00" level=debug msg="obtained new client token: AABoX9yAVTbYonP/U+s2oJmYM0hgTgGfiQugkr+DYNCG7AGgmPTwWwbF/N3F3a5z+NwsywcY1KMDcEoaZzArQgoGu84awUhM1OXVqFX1uIVxN+qTx/gw88wwniC03seGm4uGC4veH/LV6sqSYKCzz/AzMjnOLxlx8gr4v4NHRmAG42jkTivInVBER0/BTNxa9C4cN6cVDC6g55EY659X2zf0VD5a2/I3Ns54GvzedI6maJK8R/lAsiGgRQPg" Jul 05 04:44:02 masterbedroom go-librespot[12132]: time="2024-07-05T04:44:02+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jul 05 04:44:02 masterbedroom go-librespot[12132]: time="2024-07-05T04:44:02+01:00" level=debug msg="completed keyexchange" Jul 05 04:44:02 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:44:03 masterbedroom go-librespot[12132]: time="2024-07-05T04:44:03+01:00" level=debug msg="completed challenge" Jul 05 04:44:03 masterbedroom go-librespot[12132]: time="2024-07-05T04:44:03+01: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 04:44:03 masterbedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 04:44:03 masterbedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 04:44:03 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:44:04 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:44:05 masterbedroom volumio[1091]: info: Initializing connection to go-librespot Websocket Jul 05 04:44:05 masterbedroom volumio[1091]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 05 04:44:05 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:44:06 masterbedroom systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 05 04:44:06 masterbedroom systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12828. Jul 05 04:44:06 masterbedroom systemd[1]: Stopped go-librespot Daemon. Jul 05 04:44:06 masterbedroom systemd[1]: Started go-librespot Daemon. Jul 05 04:44:06 masterbedroom go-librespot[12140]: Librespot-go daemon starting... Jul 05 04:44:06 masterbedroom go-librespot[12140]: time="2024-07-05T04:44:06+01:00" level=info msg="generated new device id: bb89cbafc65611d8cff0d7f5c6bba4d9db278062" Jul 05 04:44:06 masterbedroom go-librespot[12140]: time="2024-07-05T04:44:06+01:00" level=debug msg="stored credentials found for arbitrabbit" Jul 05 04:44:06 masterbedroom go-librespot[12140]: time="2024-07-05T04:44:06+01:00" level=debug msg="obtained new client token: AACpppFVgsekyDvQXUZgWU5mtimlQzQIPLjFCgNwZhCf58h1KCvzd0BcgZSm6UqwG+Mjjq//HI5twgC7GgsrR1eSyDdIIN79N5dDEMmVaShkSFGaa4Q3nrHrp0VbdUtgoDCvwrAme1IpMCkj2YuJVGWfcsW4whYE48Osae04hyyW3ElKbOHWfjL1LE6zBfUwoyp4Z2HePwQJR3+u08gR8b6eZirro8gHr2lHu9Gn3sWSdZbOCt6Y3xrHxfoT" Jul 05 04:44:06 masterbedroom go-librespot[12140]: time="2024-07-05T04:44:06+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jul 05 04:44:06 masterbedroom go-librespot[12140]: time="2024-07-05T04:44:06+01:00" level=debug msg="completed keyexchange" Jul 05 04:44:06 masterbedroom volumio[1091]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 05 04:44:07 masterbedroom go-librespot[12140]: time="2024-07-05T04:44:07+01:00" level=debug msg="completed challenge" Jul 05 04:44:07 masterbedroom go-librespot[12140]: time="2024-07-05T04:44:07+01: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 04:44:07 masterbedroom systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 05 04:44:07 masterbedroom systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 05 04:44:07 masterbedroom volumio[1091]: info: CoreCommandRouter::Close All Modals sent Jul 05 04:44:07 masterbedroom volumio[1091]: info: ___________ PLUGINS: Run onVolumioReboot Tasks ___________ Jul 05 04:44:07 masterbedroom volumio[1091]: info: PLUGIN onReboot : networkfs Jul 05 04:44:07 masterbedroom volumio[1091]: info: PLUGIN onReboot : audiophonicsonoff Jul 05 04:44:07 masterbedroom volumio[1091]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 05 04:44:07 masterbedroom volumio[1091]: TypeError: Cannot read property 'writeSync' of undefined Jul 05 04:44:07 masterbedroom volumio[1091]: at ControllerAudiophonicsOnOff.onVolumioReboot (/data/plugins/system_controller/audiophonicsonoff/index.js:35:25) Jul 05 04:44:07 masterbedroom volumio[1091]: at PluginManager.onVolumioRebootPlugin (/volumio/app/pluginmanager.js:684:30) Jul 05 04:44:07 masterbedroom volumio[1091]: at HashMap. (/volumio/app/pluginmanager.js:668:31) Jul 05 04:44:07 masterbedroom volumio[1091]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Jul 05 04:44:07 masterbedroom volumio[1091]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Jul 05 04:44:07 masterbedroom volumio[1091]: at PluginManager.onVolumioReboot (/volumio/app/pluginmanager.js:666:20) Jul 05 04:44:07 masterbedroom volumio[1091]: at CoreCommandRouter.reboot (/volumio/app/index.js:1331:22) Jul 05 04:44:07 masterbedroom volumio[1091]: at Timeout._onTimeout (/volumio/app/plugins/system_controller/updater_comm/index.js:156:35) Jul 05 04:44:07 masterbedroom volumio[1091]: at listOnTimeout (internal/timers.js:554:17) Jul 05 04:44:07 masterbedroom volumio[1091]: at processTimers (internal/timers.js:497:7) Jul 05 04:44:07 masterbedroom volumio[1091]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 05 04:44:08 masterbedroom sudo[12157]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-07-05 04:43 Jul 05 04:44:08 masterbedroom sudo[12157]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="5fd3886148e72a9cecd88a772d1f6079fb64d11a" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="de36dcdb7799b932c717b0440e58d5fd01f99639" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 28 Jun 2024 01:21:14 PM CEST" VOLUMIO_VERSION="3.733" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="6340274f4713efb802e5b0fc2fde8446"