genielabs / HomeGenie

HomeGenie, the programmable automation intelligence
https://homegenie.it
GNU General Public License v3.0
387 stars 154 forks source link

Updates from one beta to another fail during restore from backup #466

Closed EnGamma closed 6 months ago

EnGamma commented 1 year ago

Version Release v1.4.0-beta.37 - v1.4.0-beta.37 homegenie_1.4.0-beta.37_linux-arm on Raspberry Pi 3b, Bullseye

Describe the bug Restore from beta.30 backup within beta.37 using web interface hangs at "Preparing to install..."

Expected behavior Restore from backup to perform without problem

Screenshots/Stacktrace Log output (HG running from SSH command line, not as service)

2023-04-02 13:47:00.3154 Info HomeGenie.UpdateChecker 0 HomeGenie Update Checker InstallProgress.Update COMPLETED info: Microsoft.Hosting.Lifetime[0] Application started. Press Ctrl+C to shut down. info: Microsoft.Hosting.Lifetime[0] Hosting environment: Production info: Microsoft.Hosting.Lifetime[0] Content root path: /home/pi/homegenie 2023-04-02 13:47:15.6296 Info WebServiceGateway 192.168.124.50 HTTP GET 200 /app/home/Home [OPEN] 2023-04-02 13:47:15.6461 Info WebServiceGateway 192.168.124.50 HTTP GET 304 /app/home/Home [CLOSED AFTER 0.017 seconds] 2023-04-02 13:47:16.9052 Info WebServiceGateway 192.168.124.50 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Modules.List [OPEN] 2023-04-02 13:47:17.4825 Info WebServiceGateway 192.168.124.50 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Modules.List [CLOSED AFTER 0.575 seconds] 2023-04-02 13:47:17.4965 Info WebServiceGateway 192.168.124.50 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/System.Configure/UpdateManager.UpdatesList [OPEN] 2023-04-02 13:47:17.5083 Info WebServiceGateway 192.168.124.50 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Groups.List [OPEN] 2023-04-02 13:47:17.5083 Info WebServiceGateway 192.168.124.50 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Groups.List [CLOSED AFTER 0.007 seconds] 2023-04-02 13:47:17.5295 Info WebServiceGateway 192.168.124.50 HTTP GET 200 /api/HomeAutomation.HomeGenie/Automation/Programs.List [OPEN] 2023-04-02 13:47:17.5295 Info WebServiceGateway 192.168.124.50 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/System.Configure/UpdateManager.UpdatesList [CLOSED AFTER 0.037 seconds] 2023-04-02 13:47:17.7312 Info WebServiceGateway 192.168.124.50 HTTP GET 200 /api/HomeAutomation.HomeGenie/Automation/Programs.List [CLOSED AFTER 0.2 seconds] 2023-04-02 13:47:17.7906 Info WebServiceGateway 192.168.124.50 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/System.Configure/System.Info [OPEN] 2023-04-02 13:47:17.8032 Info WebServiceGateway 192.168.124.50 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/WebSocket.GetToken [OPEN] 2023-04-02 13:47:17.8518 Info WebServiceGateway 192.168.124.50 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/WebSocket.GetToken [CLOSED AFTER 0.059 seconds] 2023-04-02 13:47:18.1884 Info WebServiceGateway 192.168.124.50 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/System.Configure/System.Info [CLOSED AFTER 0.397 seconds] 2023-04-02 13:47:30.0646 Info WebServiceGateway 192.168.124.50 HTTP POST 200 /api/HomeAutomation.HomeGenie/Config/System.Configure/Location.Set [OPEN] 2023-04-02 13:47:30.0690 Info HomeGenie.System 0 HomeGenie System HomeGenie.Status SAVING DATA 2023-04-02 13:47:30.4585 Info WebServiceGateway 192.168.124.50 HTTP POST 200 /api/HomeAutomation.HomeGenie/Config/System.Configure/Location.Set [CLOSED AFTER 0.392 seconds] 2023-04-02 13:48:22.6025 Info WebServiceGateway 192.168.124.50 HTTP POST 200 /api/HomeAutomation.HomeGenie/Config/System.Configure/System.ConfigurationRestore/homegenie_backup_20230402_085559.beta30.has_old_groups.zip [OPEN] 2023-04-02 13:48:23.0981 Info WebServiceGateway 192.168.124.50 HTTP POST 200 /api/HomeAutomation.HomeGenie/Config/System.Configure/System.ConfigurationRestore/homegenie_backup_20230402_085559.beta30.has_old_groups.zip [CLOSED AFTER 0.493 seconds] 2023-04-02 13:48:31.5171 Debug Disabling Interface HomeAutomation.X10 2023-04-02 13:48:31.5178 Info MIGService.Interfaces HomeAutomation.X10 MIG Interface Status.IsEnabled 0 2023-04-02 13:48:31.5311 Debug Disabling Interface HomeAutomation.ZWave 2023-04-02 13:48:31.5311 Info MIGService.Interfaces HomeAutomation.ZWave MIG Interface Status.IsEnabled 0 2023-04-02 13:48:31.5311 Debug Disabling Interface HomeAutomation.ZigBee 2023-04-02 13:48:31.5311 Info MIGService.Interfaces HomeAutomation.ZigBee MIG Interface Status.IsEnabled 0 2023-04-02 13:48:36.9864 Info HomeAutomation.HomeGenie.Automation 111 Automation Program Program.Status Added 2023-04-02 13:48:36.9896 Info HomeAutomation.HomeGenie.Automation 111 Automation Program Program.Status Idle 2023-04-02 13:48:37.0576 Info HomeAutomation.HomeGenie.Automation 111 Automation Program Program.Status Running 2023-04-02 13:48:37.0747 Info HomeAutomation.HomeGenie.Automation 111 Automation Program Program.Status Background 2023-04-02 13:48:37.1776 Info HomeAutomation.HomeGenie.Automation 111 Automation Program Program.Status Disabled 2023-04-02 13:48:38.0775 Info HomeAutomation.HomeGenie.Automation 111 Automation Program Program.Status Stopped 2023-04-02 13:49:00.8303 Info HomeAutomation.HomeGenie.Automation 111 Automation Program Program.Status Enabled 2023-04-02 13:49:00.8303 Info HomeAutomation.HomeGenie.Automation 111 Automation Program Program.Status Idle 2023-04-02 13:49:00.8379 Info HomeAutomation.HomeGenie.Automation 570 Automation Program Program.Status Added 2023-04-02 13:49:00.8379 Info HomeAutomation.HomeGenie.Automation 570 Automation Program Program.Status Idle 2023-04-02 13:49:00.8379 Info HomeAutomation.HomeGenie.Automation 111 Automation Program Program.Status Running 2023-04-02 13:49:00.8379 Info HomeAutomation.HomeGenie.Automation 111 Automation Program Program.Status Background 2023-04-02 13:49:00.8379 Info HomeAutomation.HomeGenie.Automation 570 Automation Program Program.Status Disabled 2023-04-02 13:49:04.3310 Info HomeAutomation.HomeGenie.Automation 570 Automation Program Program.Status Enabled 2023-04-02 13:49:04.3310 Info HomeAutomation.HomeGenie.Automation 570 Automation Program Program.Status Idle 2023-04-02 13:49:04.3310 Info HomeAutomation.HomeGenie.Automation 142 Automation Program Program.Status Added 2023-04-02 13:49:04.3310 Info HomeAutomation.HomeGenie.Automation 570 Automation Program Program.Status Running 2023-04-02 13:49:04.3310 Info HomeAutomation.HomeGenie.Automation 142 Automation Program Program.Status Idle 2023-04-02 13:49:04.3429 Info HomeAutomation.HomeGenie.Automation 570 Automation Program Program.Status Background 2023-04-02 13:49:04.3488 Info HomeAutomation.HomeGenie.Automation 142 Automation Program Program.Status Disabled 2023-04-02 13:49:04.3794 Error Error while running setup code in program 142 2023-04-02 13:49:04.3794 Info HomeAutomation.HomeGenie.Automation 142 Automation Program Runtime.Error TC: Object reference not set to an instance of an object. 2023-04-02 13:49:04.8472 Info HomeAutomation.HomeGenie.Automation 142 Automation Program Program.Status Enabled 2023-04-02 13:49:04.8477 Info HomeAutomation.HomeGenie.Automation 142 Automation Program Program.Status Idle 2023-04-02 13:49:04.8477 Info HomeAutomation.HomeGenie.Automation 571 Automation Program Program.Status Added 2023-04-02 13:49:04.8477 Info HomeAutomation.HomeGenie.Automation 571 Automation Program Program.Status Idle 2023-04-02 13:49:04.8477 Info HomeAutomation.HomeGenie.Automation 571 Automation Program Program.Status Disabled 2023-04-02 13:49:04.8603 Info HomeAutomation.HomeGenie.Automation 142 Automation Program Program.Status Running 2023-04-02 13:49:04.8679 Info HomeAutomation.HomeGenie.Automation 142 Automation Program Program.Status Background 2023-04-02 13:49:07.2736 Info HomeAutomation.HomeGenie.Automation 571 Automation Program Program.Status Enabled 2023-04-02 13:49:07.2736 Info HomeAutomation.HomeGenie.Automation 571 Automation Program Program.Status Idle 2023-04-02 13:49:07.2788 Info HomeAutomation.HomeGenie.Automation 95 Automation Program Program.Status Added 2023-04-02 13:49:07.2788 Info HomeAutomation.HomeGenie.Automation 95 Automation Program Program.Status Idle 2023-04-02 13:49:07.2788 Info HomeAutomation.HomeGenie.Automation 95 Automation Program Program.Status Disabled 2023-04-02 13:49:07.2788 Info HomeAutomation.HomeGenie.Automation 571 Automation Program Program.Status Running 2023-04-02 13:49:09.0816 Info HomeAutomation.HomeGenie.Automation 95 Automation Program Program.Status Enabled 2023-04-02 13:49:09.0816 Info HomeAutomation.HomeGenie.Automation 95 Automation Program Program.Status Idle 2023-04-02 13:49:09.1238 Info HomeAutomation.HomeGenie.Automation 77 Automation Program Program.Status Added 2023-04-02 13:49:09.1474 Info HomeAutomation.HomeGenie.Automation 95 Automation Program Program.Status Setup 2023-04-02 13:49:09.1639 Info HomeAutomation.HomeGenie.Automation 95 Automation Program Program.Status Idle 2023-04-02 13:49:09.1639 Info HomeAutomation.HomeGenie.Automation 95 Automation Program Program.Status Running 2023-04-02 13:49:09.2353 Info HomeAutomation.HomeGenie.Automation 95 Automation Program Program.Status Background 2023-04-02 13:49:12.6023 Info HomeAutomation.HomeGenie.Automation 34 Automation Program Program.Status Added 2023-04-02 13:49:12.6023 Info HomeAutomation.HomeGenie.Automation 34 Automation Program Program.Status Idle 2023-04-02 13:49:12.6078 Info HomeAutomation.HomeGenie.Automation 34 Automation Program Program.Status Disabled 2023-04-02 13:49:14.1578 Info HomeAutomation.HomeGenie.Automation 34 Automation Program Program.Status Enabled 2023-04-02 13:49:14.1578 Info HomeAutomation.HomeGenie.Automation 34 Automation Program Program.Status Idle 2023-04-02 13:49:14.1578 Info HomeAutomation.HomeGenie.Automation 572 Automation Program Program.Status Added 2023-04-02 13:49:14.1578 Info HomeAutomation.HomeGenie.Automation 572 Automation Program Program.Status Idle 2023-04-02 13:49:14.1682 Info HomeAutomation.HomeGenie.Automation 572 Automation Program Program.Status Disabled 2023-04-02 13:49:14.1682 Info HomeAutomation.HomeGenie.Automation 34 Automation Program Program.Status Running 2023-04-02 13:49:14.7821 Info HomeAutomation.HomeGenie.Automation 572 Automation Program Program.Status Enabled 2023-04-02 13:49:14.7821 Info HomeAutomation.HomeGenie.Automation 572 Automation Program Program.Status Idle 2023-04-02 13:49:14.7896 Info HomeAutomation.HomeGenie.Automation 505 Automation Program Program.Status Added 2023-04-02 13:49:14.7896 Info HomeAutomation.HomeGenie.Automation 505 Automation Program Program.Status Idle 2023-04-02 13:49:14.7896 Info HomeAutomation.HomeGenie.Automation 505 Automation Program Program.Status Disabled 2023-04-02 13:49:14.7896 Info HomeAutomation.HomeGenie.Automation 572 Automation Program Program.Status Running 2023-04-02 13:49:14.8105 Info HomeAutomation.HomeGenie.Automation 572 Automation Program Program.Status Background 2023-04-02 13:49:24.3869 Info HomeAutomation.HomeGenie.Automation 505 Automation Program Program.Status Enabled 2023-04-02 13:49:24.4586 Info HomeAutomation.HomeGenie.Automation 505 Automation Program Program.Status Idle 2023-04-02 13:49:25.3495 Info HomeAutomation.HomeGenie.Automation 900 Automation Program Program.Status Added Killed

Separate attempt to restore from backup with HG running as a service:

[pi@HA-PI:~]$ sudo systemctl status homegenie ● homegenie.service - HomeGenie Loaded: loaded (/etc/systemd/system/homegenie.service; enabled; vendor preset: enabled) Active: failed (Result: signal) since Sun 2023-04-02 14:18:56 EDT; 20s ago Process: 25963 ExecStart=/home/pi/homegenie/HomeGenie (code=killed, signal=KILL) Main PID: 25963 (code=killed, signal=KILL) CPU: 58.057s

Apr 02 14:18:32 HA-PI HomeGenie[25963]: 2023-04-02 14:18:32.8900 Info HomeAutomation.HomeGenie.Automation 95 Automation Program Program.Status Enabled Apr 02 14:18:32 HA-PI HomeGenie[25963]: 2023-04-02 14:18:32.8900 Info HomeAutomation.HomeGenie.Automation 95 Automation Program Program.Status Idle Apr 02 14:18:32 HA-PI HomeGenie[25963]: 2023-04-02 14:18:32.9183 Info HomeAutomation.HomeGenie.Automation 95 Automation Program Program.Status Setup Apr 02 14:18:32 HA-PI HomeGenie[25963]: 2023-04-02 14:18:32.9183 Info HomeAutomation.HomeGenie.Automation 95 Automation Program Program.Status Idle Apr 02 14:18:32 HA-PI HomeGenie[25963]: 2023-04-02 14:18:32.9183 Info HomeAutomation.HomeGenie.Automation 95 Automation Program Program.Status Running Apr 02 14:18:32 HA-PI HomeGenie[25963]: 2023-04-02 14:18:32.9351 Info HomeAutomation.HomeGenie.Automation 95 Automation Program Program.Status Background Apr 02 14:18:32 HA-PI HomeGenie[25963]: 2023-04-02 14:18:32.9728 Info HomeAutomation.HomeGenie.Automation 77 Automation Program Program.Status Added Apr 02 14:18:56 HA-PI systemd[1]: homegenie.service: Main process exited, code=killed, status=9/KILL Apr 02 14:18:56 HA-PI systemd[1]: homegenie.service: Failed with result 'signal'. Apr 02 14:18:56 HA-PI systemd[1]: homegenie.service: Consumed 58.057s CPU time. `

Additional context Had beta.30 running okay until now and decided to move to beta.37. I first tried update entirely from within web app interface but that hung on:

Copying file: libSystem.IO.Compression.Native.so

Then did a manual 1) download homegenie_1.4.0-beta.37_linux-arm.zip, 2) unzip overwrite of home/pi/homegenie with above results

tuicemen commented 1 year ago

I've not updated to the latest beta yet as I'm out of town. However I've had issues with updating in the past and the 64 bit HG betas. I suspect this is due to the issue @genemars stated here https://github.com/genielabs/HomeGenie/issues/464#issuecomment-1485981667

EnGamma commented 1 year ago

I've not updated to the latest beta yet as I'm out of town. However I've had issues with updating in the past and the 64 bit HG betas. I suspect this is due to the issue @genemars stated here #464 (comment)

I think that explains part of what I saw trying to do the in-process update (hanging on .so files), but I'm not sure it explains the clean-install-followed-by-restore-from-backup fail, which I would think shouldn't be trying to overwrite the .so files.