search

genielabs / HomeGenie

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

Scheduler stopped working but shows (wrong) in Log #345

Closed kaykingtoo closed 1 year ago

kaykingtoo commented 5 years ago

Expected behavior

Every 10 minutes turn off listed X10 modules

Actual behavior

Worked fist 24hours., now nothing sent via CM15 (confirmed per 2nd cm15 activity monitor), log shows "info" showing it every second, not every 10 minutes.

Steps to reproduce the problem starting from a fresh install

  1. make new scheduler, set to run exact time, then set to run every 10 minutes
  2. attach some x10 modules
  3. pick code snippet:
    turn off all selected modules $$.boundModules.off();

Log shows it running every second as "info" but nothing comes out of CM15. Log sample below.

Specifications

Additional configuration notes:

sample log section:

2018-11-20 15:36:12.0280 Info HomeAutomation.HA-Bridge 2 - Meter.Watts 35.17
2018-11-20 15:36:12.0773 Info HomeAutomation.X10 A3 X10 Module Meter.Watts 0.0 2018-11-20 15:36:12.1559 Info HomeAutomation.X10 A16 X10 Module Meter.Watts 0.0 2018-11-20 15:36:12.2171 Info HomeAutomation.X10 B5 X10 Module Meter.Watts 0.0 2018-11-20 15:36:12.2971 Info HomeAutomation.X10 B6 X10 Module Meter.Watts 0.0 2018-11-20 15:36:12.3635 Info HomeAutomation.X10 B10 X10 Module Meter.Watts 19.93 2018-11-20 15:36:12.5634 Info HomeAutomation.EnergyMonitor 1 - Program.UiRefresh Energy Monitor 2018-11-20 15:36:13.1525 Info WebServiceGateway 192.168.7.129 HTTP GET 200 /hg/html/images/common/led_green.png 2018-11-20 15:36:13.2088 Info WebServiceGateway 192.168.7.129 HTTP GET 304 /hg/html/images/common/led_green.png 2018-11-20 15:36:14.2743 Info WebServiceGateway 192.168.7.103 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Modules.Get/HomeAutomation.EnergyMonitor/1/ 2018-11-20 15:36:14.2929 Info WebServiceGateway 192.168.7.103 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Modules.Get/HomeAutomation.EnergyMonitor/1/ 2018-11-20 15:36:14.6641 Info HomeAutomation.EnergyMonitor 1 - Program.UiRefresh Energy Monitor 2018-11-20 15:36:15.2025 Info WebServiceGateway 192.168.7.129 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Modules.Get/HomeAutomation.EnergyMonitor/1/ 2018-11-20 15:36:15.2668 Info WebServiceGateway 192.168.7.129 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Modules.Get/HomeAutomation.EnergyMonitor/1/ 2018-11-20 15:36:15.2948 Info WebServiceGateway 192.168.7.129 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Modules.Get/HomeAutomation.EnergyMonitor/1/ 2018-11-20 15:36:15.2930 Info WebServiceGateway 192.168.7.129 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Modules.Get/HomeAutomation.EnergyMonitor/1/ 2018-11-20 15:36:16.3424 Info WebServiceGateway 192.168.7.103 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Modules.Get/HomeAutomation.EnergyMonitor/1/ 2018-11-20 15:36:16.3601 Info WebServiceGateway 192.168.7.103 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Modules.Get/HomeAutomation.EnergyMonitor/1/ 2018-11-20 15:36:19.6541 Info WebServiceGateway 192.168.7.129 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Interfaces.List/ 2018-11-20 15:36:19.6692 Info WebServiceGateway 192.168.7.129 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Interfaces.List/ 2018-11-20 15:36:20.7819 Info WebServiceGateway 192.168.7.103 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Interfaces.List/ 2018-11-20 15:36:20.7929 Info WebServiceGateway 192.168.7.103 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Interfaces.List/ 2018-11-20 15:36:23.4881 Debug 5D-20-74-8B-10-EF
2018-11-20 15:36:23.4893 Debug RFCOM: 5D-20-74-8B-10-EF 2018-11-20 15:36:23.4893 Info HomeAutomation.X10 RF X10 RF 2018-11-20 15:36:23.5172 Debug Command On 2018-11-20 15:36:23.5256 Info HomeAutomation.X10 B10 - Status.Level 1
2018-11-20 15:36:23.6081 Debug 5D-20-74-8B-10-EF
2018-11-20 15:36:23.6091 Warn Ignoring repeated 2018-11-20 15:36:23.7201 Debug 5D-20-74-8B-10-EF
2018-11-20 15:36:23.7211 Warn Ignoring repeated 2018-11-20 15:36:23.8241 Debug 5D-20-74-8B-10-EF
2018-11-20 15:36:23.8252 Warn Ignoring repeated 2018-11-20 15:36:23.9363 Debug 5D-20-74-8B-10-EF
2018-11-20 15:36:23.9373 Warn Ignoring repeated 2018-11-20 15:36:24.0401 Debug 5A-02-00-EF
2018-11-20 15:36:24.0412 Debug PLCRX: 5A-02-00-EF 2018-11-20 15:36:24.0418 Debug FNMAP: 0 2018-11-20 15:36:24.0423 Debug DATA : 2018-11-20 15:36:24.0432 Debug
2018-11-20 15:36:24.5167 Info HomeAutomation.X10 RF X10 RF 2018-11-20 15:36:24.6241 Debug 5A-02-01-E2
2018-11-20 15:36:24.6251 Debug PLCRX: 5A-02-01-E2 2018-11-20 15:36:24.6257 Debug FNMAP: 1 2018-11-20 15:36:24.6294 Debug DATA : 2018-11-20 15:36:24.6342 Debug
2018-11-20 15:36:24.6362 Debug
2018-11-20 15:36:24.6477 Info HomeAutomation.X10 B10 - Status.Level 1
2018-11-20 15:36:24.9876 Info HomeAutomation.EnergyMonitor 1 - Program.UiRefresh Energy Monitor 2018-11-20 15:36:25.0521 Debug 5A-02-00-EF
2018-11-20 15:36:25.0531 Debug PLCRX: 5A-02-00-EF 2018-11-20 15:36:25.0537 Debug FNMAP: 0 2018-11-20 15:36:25.0543 Debug DATA : 2018-11-20 15:36:25.0552 Debug
2018-11-20 15:36:25.4562 Debug 5A-02-01-E2
2018-11-20 15:36:25.4571 Debug PLCRX: 5A-02-01-E2 2018-11-20 15:36:25.4578 Debug FNMAP: 1 2018-11-20 15:36:25.4583 Debug DATA : 2018-11-20 15:36:25.4583 Debug
2018-11-20 15:36:25.4596 Debug
2018-11-20 15:36:25.4607 Info HomeAutomation.X10 B10 - Status.Level 1
2018-11-20 15:36:25.4972 Debug 55
2018-11-20 15:36:25.5053 Debug 0
2018-11-20 15:36:25.5571 Info WebServiceGateway 192.168.7.129 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Modules.Get/HomeAutomation.EnergyMonitor/1/ 2018-11-20 15:36:25.6738 Info WebServiceGateway 192.168.7.129 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Modules.Get/HomeAutomation.EnergyMonitor/1/ 2018-11-20 15:36:25.7111 Info WebServiceGateway 192.168.7.103 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Modules.Get/HomeAutomation.EnergyMonitor/1/ 2018-11-20 15:36:25.7365 Info WebServiceGateway 192.168.7.103 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Modules.Get/HomeAutomation.EnergyMonitor/1/ 2018-11-20 15:36:27.0454 Info HomeAutomation.EnergyMonitor 1 - Program.UiRefresh Energy Monitor 2018-11-20 15:36:27.3661 Info WebServiceGateway 192.168.7.103 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Modules.Get/HomeAutomation.EnergyMonitor/1/ 2018-11-20 15:36:27.3836 Info WebServiceGateway 192.168.7.103 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Modules.Get/HomeAutomation.EnergyMonitor/1/ 2018-11-20 15:36:28.2284 Info WebServiceGateway 192.168.7.129 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Modules.Get/HomeAutomation.EnergyMonitor/1/ 2018-11-20 15:36:28.2443 Info WebServiceGateway 192.168.7.129 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Modules.Get/HomeAutomation.EnergyMonitor/1/ 2018-11-20 15:36:30.3271 Info WebServiceGateway 192.168.7.129 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Interfaces.List/ 2018-11-20 15:36:30.3420 Info WebServiceGateway 192.168.7.129 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Interfaces.List/ 2018-11-20 15:36:30.7693 Info WebServiceGateway 192.168.7.103 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Interfaces.List/ 2018-11-20 15:36:30.7824 Info WebServiceGateway 192.168.7.103 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Interfaces.List/ 2018-11-20 15:36:33.4401 Debug 5D-20-74-8B-10-EF
2018-11-20 15:36:33.4415 Debug RFCOM: 5D-20-74-8B-10-EF 2018-11-20 15:36:33.4424 Info HomeAutomation.X10 RF X10 RF 2018-11-20 15:36:33.4772 Debug Command On 2018-11-20 15:36:33.4861 Info HomeAutomation.X10 B10 - Status.Level 1
2018-11-20 15:36:33.5611 Debug 5D-20-74-8B-10-EF
2018-11-20 15:36:33.5623 Warn Ignoring repeated 2018-11-20 15:36:33.6721 Debug 5D-20-74-8B-10-EF
2018-11-20 15:36:33.6731 Warn Ignoring repeated 2018-11-20 15:36:33.7761 Debug 5D-20-74-8B-10-EF
2018-11-20 15:36:33.7784 Warn Ignoring repeated 2018-11-20 15:36:33.8881 Debug 5D-20-74-8B-10-EF
2018-11-20 15:36:33.8891 Warn Ignoring repeated 2018-11-20 15:36:34.0001 Debug 5A-02-00-EF
2018-11-20 15:36:34.0013 Debug PLCRX: 5A-02-00-EF 2018-11-20 15:36:34.0013 Debug FNMAP: 0 2018-11-20 15:36:34.0024 Debug DATA : 2018-11-20 15:36:34.0033 Debug
2018-11-20 15:36:34.4767 Info HomeAutomation.X10 RF X10 RF 2018-11-20 15:36:34.5870 Debug 5A-02-01-E2
2018-11-20 15:36:34.5881 Debug PLCRX: 5A-02-01-E2 2018-11-20 15:36:34.5888 Debug FNMAP: 1 2018-11-20 15:36:34.5894 Debug DATA : 2018-11-20 15:36:34.5902 Debug
2018-11-20 15:36:34.5902 Debug
2018-11-20 15:36:34.5918 Info HomeAutomation.X10 B10 - Status.Level 1
2018-11-20 15:36:35.0231 Debug 5A-02-00-EF
2018-11-20 15:36:35.0241 Debug PLCRX: 5A-02-00-EF 2018-11-20 15:36:35.0248 Debug FNMAP: 0 2018-11-20 15:36:35.0254 Debug DATA : 2018-11-20 15:36:35.0373 Debug
2018-11-20 15:36:35.1583 Info HomeAutomation.EnergyMonitor 1 - Program.UiRefresh Energy Monitor 2018-11-20 15:36:35.4270 Debug 5A-02-01-E2
2018-11-20 15:36:35.4281 Debug PLCRX: 5A-02-01-E2 2018-11-20 15:36:35.4288 Debug FNMAP: 1 2018-11-20 15:36:35.4294 Debug DATA : 2018-11-20 15:36:35.4302 Debug
2018-11-20 15:36:35.4302 Debug
2018-11-20 15:36:35.4318 Info HomeAutomation.X10 B10 - Status.Level 1
2018-11-20 15:36:35.4605 Debug 55
2018-11-20 15:36:35.4675 Debug 0
2018-11-20 15:36:35.7289 Info WebServiceGateway 192.168.7.103 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Modules.Get/HomeAutomation.EnergyMonitor/1/ 2018-11-20 15:36:35.7433 Info WebServiceGateway 192.168.7.103 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Modules.Get/HomeAutomation.EnergyMonitor/1/ 2018-11-20 15:36:36.2333 Info WebServiceGateway 192.168.7.129 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Modules.Get/HomeAutomation.EnergyMonitor/1/ 2018-11-20 15:36:36.2587 Info WebServiceGateway 192.168.7.129 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Modules.Get/HomeAutomation.EnergyMonitor/1/ 2018-11-20 15:36:37.2157 Info HomeAutomation.EnergyMonitor 1 - Program.UiRefresh Energy Monitor 2018-11-20 15:36:37.5688 Info WebServiceGateway 192.168.7.103 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Modules.Get/HomeAutomation.EnergyMonitor/1/ 2018-11-20 15:36:37.5883 Info WebServiceGateway 192.168.7.103 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Modules.Get/HomeAutomation.EnergyMonitor/1/ 2018-11-20 15:36:37.6130 Info WebServiceGateway 192.168.7.129 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Modules.Get/HomeAutomation.EnergyMonitor/1/ 2018-11-20 15:36:37.6305 Info WebServiceGateway 192.168.7.129 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Modules.Get/HomeAutomation.EnergyMonitor/1/ 2018-11-20 15:36:38.4913 Info WebServiceGateway 192.168.7.129 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Interfaces.List/ 2018-11-20 15:36:38.4985 Info WebServiceGateway 192.168.7.129 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Interfaces.List/ 2018-11-20 15:36:40.7669 Info WebServiceGateway 192.168.7.103 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Interfaces.List/ 2018-11-20 15:36:40.7817 Info WebServiceGateway 192.168.7.103 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Interfaces.List/ 2018-11-20 15:36:40.9762 Debug 5D-20-74-8B-10-EF
2018-11-20 15:36:40.9774 Debug RFCOM: 5D-20-74-8B-10-EF 2018-11-20 15:36:40.9783 Info HomeAutomation.X10 RF X10 RF 2018-11-20 15:36:40.9956 Debug Command On 2018-11-20 15:36:41.0042 Info HomeAutomation.X10 B10 - Status.Level 1
2018-11-20 15:36:41.0751 Debug 5D-20-74-8B-10-EF
2018-11-20 15:36:41.0773 Warn Ignoring repeated 2018-11-20 15:36:41.1921 Debug 5D-20-74-8B-10-EF
2018-11-20 15:36:41.1931 Warn Ignoring repeated 2018-11-20 15:36:41.3040 Debug 5D-20-74-8B-10-EF
2018-11-20 15:36:41.3050 Warn Ignoring repeated 2018-11-20 15:36:41.3322 Info HomeAutomation.EnergyMonitor 1 - Program.UiRefresh Energy Monitor 2018-11-20 15:36:41.3761 Debug 5A-02-00-EF
2018-11-20 15:36:41.3783 Debug PLCRX: 5A-02-00-EF 2018-11-20 15:36:41.3801 Debug FNMAP: 0 2018-11-20 15:36:41.3828 Debug DATA : 2018-11-20 15:36:41.3976 Debug
2018-11-20 15:36:41.4110 Debug 5D-20-74-8B-10-EF
2018-11-20 15:36:41.4121 Warn Ignoring repeated 2018-11-20 15:36:41.9281 Debug 5A-02-00-EF
2018-11-20 15:36:41.9291 Debug PLCRX: 5A-02-00-EF 2018-11-20 15:36:41.9297 Debug FNMAP: 0 2018-11-20 15:36:41.9303 Debug DATA : 2018-11-20 15:36:41.9312 Debug
2018-11-20 15:36:41.9955 Info HomeAutomation.X10 RF X10 RF 2018-11-20 15:36:42.0760 Info WebServiceGateway 192.168.7.103 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Modules.Get/HomeAutomation.EnergyMonitor/1/ 2018-11-20 15:36:42.0941 Info WebServiceGateway 192.168.7.103 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Modules.Get/HomeAutomation.EnergyMonitor/1/ 2018-11-20 15:36:42.2337 Info WebServiceGateway 192.168.7.129 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Modules.Get/HomeAutomation.EnergyMonitor/1/ 2018-11-20 15:36:42.2582 Info WebServiceGateway 192.168.7.129 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Modules.Get/HomeAutomation.EnergyMonitor/1/ 2018-11-20 15:36:42.4384 Info HomeAutomation.HA-Bridge 2 - Meter.Watts 34.91
2018-11-20 15:36:42.4712 Info HomeAutomation.X10 A3 X10 Module Meter.Watts 0.0 2018-11-20 15:36:42.5350 Debug 5A-02-01-E2
2018-11-20 15:36:42.5385 Debug PLCRX: 5A-02-01-E2 2018-11-20 15:36:42.5403 Debug FNMAP: 1 2018-11-20 15:36:42.5420 Debug DATA : 2018-11-20 15:36:42.5565 Debug
2018-11-20 15:36:42.5702 Debug
2018-11-20 15:36:42.5574 Info HomeAutomation.X10 A16 X10 Module Meter.Watts 0.0 2018-11-20 15:36:42.5765 Info HomeAutomation.X10 B10 - Status.Level 1
2018-11-20 15:36:42.6480 Info HomeAutomation.X10 B5 X10 Module Meter.Watts 0.0 2018-11-20 15:36:42.7006 Info HomeAutomation.X10 B6 X10 Module Meter.Watts 0.0 2018-11-20 15:36:42.7579 Info HomeAutomation.X10 B10 X10 Module Meter.Watts 20.23 2018-11-20 15:36:42.9580 Debug 5A-02-01-E2
2018-11-20 15:36:42.9591 Debug PLCRX: 5A-02-01-E2 2018-11-20 15:36:42.9597 Debug FNMAP: 1

kaykingtoo commented 5 years ago

So sending commands that worked, studying Log, I see the above does nothing... So I replaced exact time and every 10 minutes with crone (0/10 ), redid the module picks, and .... no change...

rebooted and now it took my changes and is working again... so it seems to me scheduler changes do not become effective until after a program restart. Anyone confirm this?

Hovering over the schedule shows correct past and future occurrences - first time then after a few minutes seems to go into netherland and show some wierd comment that is not accurate - like last run 13 days ago and not showing any future runs to come; yet 10 min later it worked again.

being x10, I need to send the off command multiple times to be sure it takes; log shows it does not repeat multiple off commands - probably need to add a delay of 3 sec between each off command in the script. will try that next.

hope this helps someone figure out wierd stuff in their scheduler action also.

kaykingtoo commented 5 years ago

Would anyone suggest going to latest beta to solve this? I thought it was solved, but looking at the log I see this new 10 min timer and only 2 modules in list is running every second! And even MORE weird, my original list of 6 m odules I deleted to remake this scheduler with crone and 2 modules - IS BACK AND RUNNING ALSO - as that reporting of watts used stuff!!

Time to go to latest beta maybe?

genemars commented 5 years ago

give it a try

mralapete commented 5 years ago

Type mono --version to see what Mono version is running on your install. It's important to know what version you're running. I've a feeling it's the standard repo version, 4.6.2 if I'm not mistaken. You may need to upgrade to 5.4 or higher. Is this a gdebi install, a manual install or is it built from source.

kaykingtoo commented 5 years ago

ver 4.6.2 here. stretch lite.

so googled how to upgrade to 5.12 and found:

sudo apt-get install --only-upgrade mono-complete

but that does not work; reports:

Reading package lists... Done Building dependency tree Reading state information... Done Skipping mono-complete, it is not installed and only upgrades are requested. 0 upgraded, 0 newly installed, 0 to remove and 4 not upgraded.

I will continue researching how to do this. thanks.

kaykingtoo commented 5 years ago

Seems upgrading mono is not easy task... would it get updated if I try to overwrite my HG 571 with latest beta install?

mralapete commented 5 years ago

Can't be done. You must do a manual install of HomeGenie then add the Mono project to you sources list and install Mono that way. It's all documented on the Mono project page. The manual install of homegenie is documented on the homegenie.it page.

kaykingtoo commented 5 years ago

I am too newbie like to understand what you said Mr. alapete. but I Thank you for trying to help.

I have no idea how this 'mono' thing got loaded on my SD card. I SUSPECT it was by either HG install or was preloaded with stretch Lite 6/2018 image.

Bounz commented 5 years ago

Mono is an open source implementation of Microsoft's .NET Framework, so it allows users to run .Net programs on Linux. You have an outdated version of Mono on your RPi. To upgrade it follow installation instructions described here: https://www.mono-project.com/download/stable/#download-lin-raspbian. It's not complicated (5 commands in terminal). I suggest you install mono-complete instead of mono-devel on the last step.

kaykingtoo commented 5 years ago

I feel like a fool asking, but how do I tell if I have raspbian 8 or 9? I will begin googling to see if I can figure it out. thank you.

kaykingtoo commented 5 years ago

found cat /etc/os-release so got answer. sorry.

kaykingtoo commented 5 years ago

Got thru first 4 steps fine. got to 91% thru sudo apt install mono-complete when it locked up pi. It was adding IIRC 682 programs, modifying a bunch and upgrading some. I could not recover via SSH or reboot so have to wait until I can get to the pi location and cycle power to see how badly I screwed it up. The above took approx. 1.5 hours!

tuicemen commented 5 years ago

installing mono complete takes a long time and if I remember when I installed it the screen blanked for several mins before the last stages completed( around the (90% mark) this made me thing it had locked up, so your install may have worked.

kaykingtoo commented 5 years ago

tnx. I let it sit for 45 minutes before trying to ctl x and z. I am here and rebooted; it reports 5.16 version! But HG totally ignores my x10 commands.

I just tried to run again and it says all ok (except for that 30 needing upgrade?):

pi@raspberrypi:~ $ sudo apt install mono-complete Reading package lists... Done Building dependency tree Reading state information... Done mono-complete is already the newest version (5.16.0.179-0xamarin1+raspbian9b1). 0 upgraded, 0 newly installed, 0 to remove and 30 not upgraded.

Not sure why HG does not work - it changes the on/off lite in the modules but no X10 PLC stuff, it works with sending to Habridge... I will try again in a while and see if I can figure out what is broke. Cycled power on cm15, no change. I might just upgrade to beta .21 from my .16 HG and see if that re aligns it...