search

genielabs / HomeGenie

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

HG 1.1 X10 PLC send broken #237

Closed bkenobi closed 8 years ago

bkenobi commented 8 years ago

Documented in forum thread: http://www.homegenie.it/forum/index.php?topic=1194.0

In short, HG 1.1 has an issue with sending PLC commands correctly to the CM15A. The issue is repeatable and I can recreate it with the Advanced Smart Lights APP but it should be reproducible with other approaches as well. I have included mono output for r478 (working), r491 (working), and r500 (broken). I included the backup file used as well such that the problem can be recreated.

System configuration: RPi v1B CM15A Raspian Wheezy 5/5/2015

genemars commented 8 years ago

so is the delay only happening when trying to issue a command after a RF code is received? is the delay also happening if you change the trigger to be on the PLC event (O2 ON) instead of the RF event? I will look into this fix for the next release.

bkenobi commented 8 years ago

No, the delay happens for both RF and PLC issued commands.

bkenobi commented 8 years ago

There is also confirmation that the delay happens on both RPiv1 and RPiv2 if not all systems.

genemars commented 8 years ago

what happen if you put a Pause(1) before sending the command? (just trying to locate if the problem is that after RF is received new xtenlib won't wait for ACK 0x55)

genemars commented 8 years ago

are you using RunAsyncTask for issuing commands in the smart light app?

bkenobi commented 8 years ago

I broke my test installation so I'll build a new one and try issuing a pause. I'm also going to try using a simple wizard script to make sure it's not just a C# issue. I don't issue RunAsyncTask so I assume it would be waiting for the response prior to issuing the next command.

genemars commented 8 years ago

I just tried a wizard script on RF event and it's running fine on my side.

genemars commented 8 years ago 
2015-11-15 16:10:07.8228 Debug 5D-20-60-9F-00-FF
2015-11-15 16:10:07.8228 Debug RFCOM: 5D-20-60-9F-00-FF
2015-11-15 16:10:07.8239 Info HomeAutomation.X10    RF  X10 RF Receiver Receiver.RawData    5D 20 60 9F 00 FF
2015-11-15 16:10:07.8401 Info HomeAutomation.X10.RF 1   Virtual Module  Status.Level    1
2015-11-15 16:10:07.8271 Info HomeAutomation.HomeGenie.Automation   1017    Automation Program  Program.Status  Running
2015-11-15 16:10:07.8270 Debug Command On HouseCode A UnitCode 1
2015-11-15 16:10:07.8286 Info HomeAutomation.X10    A1  -   Status.Level    1
2015-11-15 16:10:07.9189 Debug 5D-20-60-9F-00-FF
2015-11-15 16:10:07.9189 Warn Ignoring repeated message within 500ms
2015-11-15 16:10:08.0394 Debug 5D-20-60-9F-00-FF
2015-11-15 16:10:08.0400 Warn Ignoring repeated message within 500ms
2015-11-15 16:10:08.1588 Debug 5D-20-60-9F-00-FF
2015-11-15 16:10:08.1588 Warn Ignoring repeated message within 500ms
2015-11-15 16:10:08.6600 Debug 04-E1
2015-11-15 16:10:08.8661 Info HomeAutomation.X10    RF  X10 RF Receiver Receiver.RawData    
2015-11-15 16:10:09.1594 Debug 55
2015-11-15 16:10:09.1598 Debug Command succesfull
2015-11-15 16:10:09.1598 Debug 06-E2
2015-11-15 16:10:09.6713 Debug 55
2015-11-15 16:10:09.6717 Debug Command succesfull
2015-11-15 16:10:09.6729 Info HomeAutomation.X10    B5  -   Status.Level    1
bkenobi commented 8 years ago

I tried the wizard script and had trouble making one that consistently ran correctly (I don't use them for any triggers so I apparently messed the function up). I tried adding a pause to the Advanced Smart Lights code and it did not seem to help. mono_nopause.txt mono_pause.txt

genemars commented 8 years ago

so it seems like anything I can figure out. Unfortunately did not even find a way of replicating this behavior till now.

bkenobi commented 8 years ago

To be clear, are you able to replicate? If not, can I provide more help? One other user on the forum can also replicate with RPi2 if that would help.

genemars commented 8 years ago

not able to replicate.

bkenobi commented 8 years ago

I installed HG r500 on my win7 laptop, restored the backup I posted on the forum thread, and attached my backup CM15A. When I send "O2 ON" there is a long delay and eventually the light turns on (A8). I launched HG from the command line and saved the mono output and can see that I get the same error I do when running on RPi.

2015-11-15 16:03:14.3986 Debug 5D-20-20-DF-10-EF 2015-11-15 16:03:14.3986 Debug RFCOM: 5D-20-20-DF-10-EF 2015-11-15 16:03:14.4046 Info HomeAutomation.X10 RF X10 RF Receiver Receiver.RawData 5D 20 20 DF 10 EF 2015-11-15 16:03:14.4046 Debug Command On HouseCode O UnitCode 2 2015-11-15 16:03:14.4046 Info HomeAutomation.X10 O2 - Status.L evel 1 2015-11-15 16:03:14.8996 Debug 04-6D 2015-11-15 16:03:15.4156 Info HomeAutomation.X10 RF X10 RF Receiver Receiver.RawData 2015-11-15 16:03:19.9069 Warn Previous command timed out, resending (1) 2015-11-15 16:03:19.9149 Debug 06-62 2015-11-15 16:03:24.9232 Warn Previous command timed out, resending (1) 2015-11-15 16:03:24.9322 Info HomeAutomation.X10 A8 - Status.L evel 1

(sorry about the formatting, that's what the DOS window ended up with.

mono_win7.txt

bkenobi commented 8 years ago

I built a wizard script to do the same basic action as the full ASL code and it does not seem to have the delay in windows.

mono_win7_1.txt X10_test.hgx.xml.txt

bkenobi commented 8 years ago

I tried the same wizard script on my RPi and I do not see the error. Is it possible that the error is only reproducible via C#? Suggestions are welcome.

genemars commented 8 years ago

can you provide a c# program to let me reproduce the issue? is the error also happening if you don't restore your backup and try to reconfigure?

bkenobi commented 8 years ago

The Advanced Smart Lights code causes the issue consistently. I can strip it down to the core code that pertains to this issue if that would help. I'll try setting up from a factory default since the test only requires 2 modules and 1 APP.

genemars commented 8 years ago

just create a simple c# program that detects an RF event and then issue a PLC command.

bkenobi commented 8 years ago

I created a simple C# program that looks for "O2 ON". If found, it turns on A8, pauses 15 seconds, and turns A8 off. I tried this code on my full setup with r499 and it had the delay. I exported the code to my test configuration using r500 and still had the delay (mono-test.txt). I reset the configuration to factory and imported the APP and still saw the delay (mono-test1.txt). mono-test.txt mono-test1.txt X10_delay_bug_test.txt

bkenobi commented 8 years ago

I installed r500 on Win7 again. Using the stock configuration and only making required modifications (turn on X10, add modules, add APP) I tried the test again. Once again I see the long delay so it appears to be an issue with HG 1.1 + CM15A + C#. mono-test3.txt

genemars commented 8 years ago

I can replicate the issue now. I'll be working on this and let you know.

bkenobi commented 8 years ago

Great, sounds good!

genemars commented 8 years ago

I fixed it. The problem was that each task processing an event in the system was blocking until processing was complete. Since the XTenLib is firing events synchronously, even the interface I/O would block until processing was completed (eg. any WhenParameterIsChanging was complete). So I restored the old HG behavior to let event be processed asynchronously. This bug would have eventually involved any other delay observed in the system, but most interfaces fires events asynchronously, that's why it was affecting mainly X10. HG will be a little faster now :)

bkenobi commented 8 years ago

Great! My power is out for the next day or two most likely, but when the fix is incorporated into the next testing release (and my power is up) I'll give it a try.