X10 functionality broken (?) in r509

[pim555]

Hi,

Some of my automation programs that control X10 lights do not work properly anymore. Not sure if this is since r509 or earlier.

The script is attached.

As you can see from the log below, all commands are executed properly but the script is run twice and the second time, some lights are switched off which is not in the script.

Log file is below:

Code: [Select]

"2016-01-03 11:49:33.7526 Info WebServiceGateway 192.168.1.103 HTTP GET 200 /api/HomeAutomation.HomeGenie/Automation/Programs.Toggle/1062/Dashboard [OPEN]"
"2016-01-03 11:49:33.7616 Info HomeAutomation.HomeGenie.Automation 1062 Automation Program Program.Status Running"
"2016-01-03 11:49:33.8254 Info WebServiceGateway 192.168.1.103 HTTP GET 200 /api/HomeAutomation.HomeGenie/Automation/Programs.Toggle/1062/Dashboard [CLOSED AFTER 0,043 seconds]"
2016-01-03 11:49:33.8143 Debug 04-6D
2016-01-03 11:49:34.3183 Debug 55
2016-01-03 11:49:34.3187 Debug Command succesfull
2016-01-03 11:49:34.3205 Debug 06-62
2016-01-03 11:49:34.8223 Debug 55
2016-01-03 11:49:34.8227 Debug Command succesfull
"2016-01-03 11:49:34.8252 Info HomeAutomation.X10 A8 - Status.Level 1"
2016-01-03 11:49:34.8389 Debug 04-6F
"2016-01-03 11:49:35.1930 Info WebServiceGateway 192.168.1.103 HTTP GET 200 /hg/html/pages/control/widgets/homegenie/generic/light.js [CLOSED AFTER 0,025 seconds]"
"2016-01-03 11:49:35.1682 Info WebServiceGateway 192.168.1.103 HTTP GET 200 /hg/html/pages/control/widgets/homegenie/generic/light.js [OPEN]"
"2016-01-03 11:49:35.2157 Info WebServiceGateway 192.168.1.103 HTTP GET 200 /hg/html/images/indicators/bulb.png [CLOSED AFTER 0,01 seconds]"
"2016-01-03 11:49:35.2061 Info WebServiceGateway 192.168.1.103 HTTP GET 200 /hg/html/images/indicators/bulb.png [OPEN]"
"2016-01-03 11:49:35.2249 Info WebServiceGateway 192.168.1.103 HTTP GET 200 /hg/html/pages/control/widgets/homegenie/generic/light.html [OPEN]"
"2016-01-03 11:49:35.2426 Info WebServiceGateway 192.168.1.103 HTTP GET 200 /hg/html/pages/control/widgets/homegenie/generic/light.html [CLOSED AFTER 0,018 seconds]"
2016-01-03 11:49:35.3432 Debug 55
2016-01-03 11:49:35.3436 Debug Command succesfull
2016-01-03 11:49:35.3450 Debug 06-62
2016-01-03 11:49:35.8384 Debug 55
2016-01-03 11:49:35.8389 Debug Command succesfull
"2016-01-03 11:49:35.8410 Info HomeAutomation.X10 A10 - Status.Level 1"
2016-01-03 11:49:35.8555 Debug ZWaveMessage (RawData=01-0A-00-13-0A-03-26-01-1E-05-5D-8E)
2016-01-03 11:49:35.8610 Debug ZWaveMessage (Direction=Outbound, Header=SOF, NodeId=10, Type=Request, Function=SendData, CommandClass=SwitchMultilevel, CallbackId=93, CallbackStatus=NotSet)
"2016-01-03 11:49:35.8911 Info HomeAutomation.ZWave 10 ZWave Node Status.Level 0.3"
2016-01-03 11:49:35.9043 Debug ZWaveMessage (RawData=01-0A-00-13-09-03-26-01-00-05-5E-90)
2016-01-03 11:49:35.9050 Debug ZWaveMessage (Direction=Outbound, Header=SOF, NodeId=9, Type=Request, Function=SendData, CommandClass=SwitchMultilevel, CallbackId=94, CallbackStatus=NotSet)
"2016-01-03 11:49:35.9517 Info HomeAutomation.ZWave 9 ZWave Node Status.Level 0"
2016-01-03 11:49:35.9647 Debug 04-67
2016-01-03 11:49:36.0045 Trace [[[ BEGIN REQUEST ]]]
2016-01-03 11:49:36.0049 Trace WaitAck
2016-01-03 11:49:36.0049 Trace Sending Message (Node=10, CallbackId=5D, Function=SendData, CommandClass=SwitchMultilevel)
2016-01-03 11:49:36.0062 Debug 01-0A-00-13-0A-03-26-01-1E-05-5D-8E
2016-01-03 11:49:36.0421 Debug 06-01-04-01-13-01-E8
2016-01-03 11:49:36.0430 Debug ZWaveMessage (RawData=01-04-01-13-01-E8)
2016-01-03 11:49:36.0430 Debug ZWaveMessage (Direction=Inbound, Header=SOF, NodeId=0, Type=Response, Function=SendData, CommandClass=NotSet)
2016-01-03 11:49:36.0442 Debug 06
2016-01-03 11:49:36.0442 Trace SendDataReady
2016-01-03 11:49:36.1452 Debug 01-07-00-13-5D-00-00-02-B4
2016-01-03 11:49:36.1461 Debug ZWaveMessage (RawData=01-07-00-13-5D-00-00-02-B4)
2016-01-03 11:49:36.1470 Debug ZWaveMessage (Direction=Inbound, Header=SOF, NodeId=0, Type=Request, Function=SendData, CommandClass=NotSet)
2016-01-03 11:49:36.1482 Debug 06
2016-01-03 11:49:36.1488 Trace Complete
2016-01-03 11:49:36.1513 Trace [[[ END REQUEST ]]] took 146 ms
2016-01-03 11:49:36.2520 Trace [[[ BEGIN REQUEST ]]]
2016-01-03 11:49:36.2520 Trace WaitAck
2016-01-03 11:49:36.2530 Trace Sending Message (Node=9, CallbackId=5E, Function=SendData, CommandClass=SwitchMultilevel)
2016-01-03 11:49:36.2539 Debug 01-0A-00-13-09-03-26-01-00-05-5E-90
2016-01-03 11:49:36.3547 Debug 06-01-04-01-13-01-E8
2016-01-03 11:49:36.3562 Debug ZWaveMessage (Direction=Inbound, Header=SOF, NodeId=0, Type=Response, Function=SendData, CommandClass=NotSet)
2016-01-03 11:49:36.3573 Debug 06
2016-01-03 11:49:36.3547 Debug ZWaveMessage (RawData=01-04-01-13-01-E8)
2016-01-03 11:49:36.3578 Trace SendDataReady
2016-01-03 11:49:36.3600 Debug 01-07-00-13-5E-00-00-02-B7
2016-01-03 11:49:36.3626 Debug ZWaveMessage (RawData=01-07-00-13-5E-00-00-02-B7)
2016-01-03 11:49:36.3650 Debug ZWaveMessage (Direction=Inbound, Header=SOF, NodeId=0, Type=Request, Function=SendData, CommandClass=NotSet)
2016-01-03 11:49:36.3680 Debug 06
2016-01-03 11:49:36.3686 Trace Complete
2016-01-03 11:49:36.3712 Trace [[[ END REQUEST ]]] took 118 ms
2016-01-03 11:49:36.4626 Debug 55
2016-01-03 11:49:36.4650 Debug 06-63
2016-01-03 11:49:36.4626 Debug Command succesfull
2016-01-03 11:49:36.9586 Debug 55
2016-01-03 11:49:36.9586 Debug Command succesfull
"2016-01-03 11:49:36.9615 Info HomeAutomation.X10 A9 - Status.Level 0"
2016-01-03 11:49:36.9751 Debug 04-60
2016-01-03 11:49:37.4786 Debug 55
2016-01-03 11:49:37.4786 Debug Command succesfull
2016-01-03 11:49:37.4803 Debug 06-63
2016-01-03 11:49:37.9827 Debug 55
2016-01-03 11:49:37.9827 Debug Command succesfull
"2016-01-03 11:49:37.9848 Info HomeAutomation.X10 A13 - Status.Level 0"
2016-01-03 11:49:37.9985 Debug 04-68
2016-01-03 11:49:38.5027 Debug 55
2016-01-03 11:49:38.5027 Debug Command succesfull
2016-01-03 11:49:38.5043 Debug 06-63
"2016-01-03 11:49:38.5541 Info WebServiceGateway 192.168.1.103 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Interfaces.List/ [CLOSED AFTER 0,008 seconds]"
"2016-01-03 11:49:38.5464 Info WebServiceGateway 192.168.1.103 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Interfaces.List/ [OPEN]"
2016-01-03 11:49:38.9988 Debug 55
2016-01-03 11:49:38.9988 Debug Command succesfull
"2016-01-03 11:49:39.0010 Info HomeAutomation.X10 A14 - Status.Level 0"
"2016-01-03 11:49:39.0142 Info HomeAutomation.HomeGenie.Automation 1062 Automation Program Program.Status Idle"
2016-01-03 11:49:39.7989 Debug 5A-02-00-6D
2016-01-03 11:49:39.7996 Debug PLCRX: 5A-02-00-6D
2016-01-03 11:49:39.7996 Debug FNMAP: 00
2016-01-03 11:49:39.7996 Debug DATA : 6D
2016-01-03 11:49:39.8010 Debug       0) Address = A8
2016-01-03 11:49:40.0711 Debug 5A-02-01-62
2016-01-03 11:49:40.0716 Debug PLCRX: 5A-02-01-62
2016-01-03 11:49:40.0716 Debug FNMAP: 01
2016-01-03 11:49:40.0716 Debug DATA : 62
2016-01-03 11:49:40.0727 Debug       0) House code = A
2016-01-03 11:49:40.0727 Debug       0)    Command = On
"2016-01-03 11:49:40.0739 Info HomeAutomation.X10 A8 - Status.Level 1"
2016-01-03 11:49:40.3992 Debug 5A-02-00-6F
2016-01-03 11:49:40.3996 Debug PLCRX: 5A-02-00-6F
2016-01-03 11:49:40.3996 Debug FNMAP: 00
2016-01-03 11:49:40.3996 Debug DATA : 6F
2016-01-03 11:49:40.4010 Debug       0) Address = A10
2016-01-03 11:49:40.6712 Debug 5A-02-01-62
2016-01-03 11:49:40.6716 Debug PLCRX: 5A-02-01-62
2016-01-03 11:49:40.6716 Debug FNMAP: 01
2016-01-03 11:49:40.6716 Debug DATA : 62
2016-01-03 11:49:40.6728 Debug       0) House code = A
2016-01-03 11:49:40.6728 Debug       0)    Command = On
"2016-01-03 11:49:40.6740 Info HomeAutomation.X10 A10 - Status.Level 1"
2016-01-03 11:49:40.9911 Debug 5A-02-01-63
2016-01-03 11:49:40.9916 Debug PLCRX: 5A-02-01-63
2016-01-03 11:49:40.9916 Debug FNMAP: 01
2016-01-03 11:49:40.9916 Debug DATA : 63
2016-01-03 11:49:40.9928 Debug       0) House code = A
2016-01-03 11:49:40.9928 Debug       0)    Command = Off
"2016-01-03 11:49:40.9940 Info HomeAutomation.X10 A10 - Status.Level 0"
2016-01-03 11:49:41.3241 Debug 5A-02-00-60
2016-01-03 11:49:41.3246 Debug PLCRX: 5A-02-00-60
2016-01-03 11:49:41.3246 Debug FNMAP: 00
2016-01-03 11:49:41.3246 Debug DATA : 60
2016-01-03 11:49:41.3260 Debug       0) Address = A13
2016-01-03 11:49:41.5885 Debug 5A-02-01-63
2016-01-03 11:49:41.5889 Debug PLCRX: 5A-02-01-63
2016-01-03 11:49:41.5914 Debug FNMAP: 01
2016-01-03 11:49:41.5918 Debug DATA : 63
2016-01-03 11:49:41.5918 Debug       0) House code = A
2016-01-03 11:49:41.5927 Debug       0)    Command = Off
"2016-01-03 11:49:41.5927 Info HomeAutomation.X10 A13 - Status.Level 0"
2016-01-03 11:49:41.9242 Debug 5A-02-00-68
2016-01-03 11:49:41.9246 Debug PLCRX: 5A-02-00-68
2016-01-03 11:49:41.9246 Debug FNMAP: 00
2016-01-03 11:49:41.9246 Debug DATA : 68
2016-01-03 11:49:41.9261 Debug       0) Address = A14
2016-01-03 11:49:42.1886 Debug 5A-02-01-63
2016-01-03 11:49:42.1893 Debug PLCRX: 5A-02-01-63
2016-01-03 11:49:42.1898 Debug FNMAP: 01
2016-01-03 11:49:42.1898 Debug DATA : 63
2016-01-03 11:49:42.1906 Debug       0) House code = A
2016-01-03 11:49:42.1906 Debug       0)    Command = Off
"2016-01-03 11:49:42.1917 Info HomeAutomation.X10 A14 - Status.Level 0"
2016-01-03 11:49:42.5083 Debug 5A-02-01-62
2016-01-03 11:49:42.5093 Debug PLCRX: 5A-02-01-62
2016-01-03 11:49:42.5098 Debug FNMAP: 01
2016-01-03 11:49:42.5098 Debug DATA : 62
2016-01-03 11:49:42.5098 Debug       0) House code = A
2016-01-03 11:49:42.5109 Debug       0)    Command = On
"2016-01-03 11:49:42.5117 Info HomeAutomation.X10 A14 - Status.Level 1"


[pim555]

Have done some further investigation to try and isolate the problem...

I created 2 programs. The first one is:
A10 Off
A10 On

This produces below log in which it looks like A10 on/off is repeated after running the program only once:

Code: [Select]

"2016-01-04 21:37:02.6670 Info WebServiceGateway 192.168.1.103 HTTP GET 200 /api/HomeAutomation.HomeGenie/Automation/Programs.Toggle/1065/Test [OPEN]"
"2016-01-04 21:37:02.7331 Info HomeAutomation.HomeGenie.Automation 1065 Automation Program Program.Status Running"
"2016-01-04 21:37:02.7938 Info WebServiceGateway 192.168.1.103 HTTP GET 200 /api/HomeAutomation.HomeGenie/Automation/Programs.Toggle/1065/Test [CLOSED AFTER 0,127 seconds]"
2016-01-04 21:37:02.7989 Debug 04-6F
2016-01-04 21:37:03.5211 Debug 55
2016-01-04 21:37:03.5211 Debug Command succesfull
2016-01-04 21:37:03.5228 Debug 06-63
2016-01-04 21:37:04.0171 Debug 55
2016-01-04 21:37:04.0176 Debug Command succesfull
"2016-01-04 21:37:04.0206 Info HomeAutomation.X10 A10 - Status.Level 0"
2016-01-04 21:37:04.0349 Debug 04-6F
"2016-01-04 21:37:04.3276 Info WebServiceGateway 192.168.1.103 HTTP GET 200 /hg/html/pages/control/widgets/homegenie/generic/light.js [CLOSED AFTER 0,017 seconds]"
"2016-01-04 21:37:04.3102 Info WebServiceGateway 192.168.1.103 HTTP GET 200 /hg/html/pages/control/widgets/homegenie/generic/light.js [OPEN]"
"2016-01-04 21:37:04.3617 Info WebServiceGateway 192.168.1.103 HTTP GET 200 /hg/html/pages/control/widgets/homegenie/generic/light.html [CLOSED AFTER 0,016 seconds]"
"2016-01-04 21:37:04.3457 Info WebServiceGateway 192.168.1.103 HTTP GET 200 /hg/html/pages/control/widgets/homegenie/generic/light.html [OPEN]"
2016-01-04 21:37:04.5372 Debug 55
2016-01-04 21:37:04.5377 Debug Command succesfull
2016-01-04 21:37:04.5388 Debug 06-62
2016-01-04 21:37:05.0412 Debug 55
2016-01-04 21:37:05.0418 Debug Command succesfull
"2016-01-04 21:37:05.0434 Info HomeAutomation.X10 A10 - Status.Level 1"
"2016-01-04 21:37:05.0575 Info HomeAutomation.HomeGenie.Automation 1065 Automation Program Program.Status Idle"
"2016-01-04 21:37:05.6125 Info HGIC:192_168_1_120.HomeAutomation.ZWave 4 Binary Switch Meter.Watts 0.0"
"2016-01-04 21:37:05.6377 Info HomeAutomation.X10 A1 X10 Module Meter.Watts 0.0"
"2016-01-04 21:37:05.7327 Info HomeAutomation.X10 A2 X10 Module Meter.Watts 0.0"
2016-01-04 21:37:05.8414 Debug 5A-02-00-6F
2016-01-04 21:37:05.8418 Debug PLCRX: 5A-02-00-6F
2016-01-04 21:37:05.8418 Debug FNMAP: 00
2016-01-04 21:37:05.8418 Debug DATA : 6F
2016-01-04 21:37:05.8431 Debug       0) Address = A10
"2016-01-04 21:37:05.8100 Info HomeAutomation.X10 A5 X10 Module Meter.Watts 0.0"
"2016-01-04 21:37:05.9103 Info HomeAutomation.X10 A6 X10 Module Meter.Watts 0.0"
"2016-01-04 21:37:06.0206 Info HomeAutomation.X10 A8 X10 Module Meter.Watts 40.07"
2016-01-04 21:37:06.1137 Debug 5A-02-01-63
2016-01-04 21:37:06.1137 Debug PLCRX: 5A-02-01-63
2016-01-04 21:37:06.1137 Debug FNMAP: 01
2016-01-04 21:37:06.1148 Debug DATA : 63
2016-01-04 21:37:06.1148 Debug       0) House code = A
2016-01-04 21:37:06.1157 Debug       0)    Command = Off
"2016-01-04 21:37:06.1166 Info HomeAutomation.X10 A10 - Status.Level 0"
"2016-01-04 21:37:06.1022 Info HomeAutomation.X10 A9 X10 Module Meter.Watts 0.0"
"2016-01-04 21:37:06.1941 Info HomeAutomation.X10 A10 X10 Module Meter.Watts 0.0"
"2016-01-04 21:37:06.3282 Info HomeAutomation.X10 A11 X10 Module Meter.Watts 24.97"
"2016-01-04 21:37:06.4038 Info HomeAutomation.X10 A12 X10 Module Meter.Watts 0.0"
2016-01-04 21:37:06.4396 Debug 5A-02-00-6F
2016-01-04 21:37:06.4396 Debug PLCRX: 5A-02-00-6F
2016-01-04 21:37:06.4396 Debug FNMAP: 00
2016-01-04 21:37:06.4408 Debug DATA : 6F
2016-01-04 21:37:06.4408 Debug       0) Address = A10
"2016-01-04 21:37:06.4800 Info HomeAutomation.X10 A13 X10 Module Meter.Watts 0.0"
"2016-01-04 21:37:06.5607 Info HomeAutomation.X10 A14 X10 Module Meter.Watts 0.0"
"2016-01-04 21:37:06.6602 Info HomeAutomation.X10 A15 X10 Module Meter.Watts 100.05"
2016-01-04 21:37:06.7115 Debug 5A-02-01-62
2016-01-04 21:37:06.7120 Debug PLCRX: 5A-02-01-62
2016-01-04 21:37:06.7120 Debug FNMAP: 01
2016-01-04 21:37:06.7155 Debug DATA : 62
2016-01-04 21:37:06.7162 Debug       0) House code = A
2016-01-04 21:37:06.7168 Debug       0)    Command = On
"2016-01-04 21:37:06.7176 Info HomeAutomation.X10 A10 - Status.Level 1"

The second program is:
A10 Off
Pause 5
A10 On

This produces the log as below. Now it looks like two off commands and two on commands are sent in correct order.

Code: [Select]

"2016-01-04 21:38:03.5453 Info WebServiceGateway 192.168.1.103 HTTP GET 200 /api/HomeAutomation.HomeGenie/Automation/Programs.Toggle/1066/Test [CLOSED AFTER 0,015 seconds]"
"2016-01-04 21:38:03.5314 Info HomeAutomation.HomeGenie.Automation 1066 Automation Program Program.Status Running"
"2016-01-04 21:38:03.5299 Info WebServiceGateway 192.168.1.103 HTTP GET 200 /api/HomeAutomation.HomeGenie/Automation/Programs.Toggle/1066/Test [OPEN]"
2016-01-04 21:38:03.5511 Debug 04-6F
2016-01-04 21:38:04.4378 Debug 55
2016-01-04 21:38:04.4378 Debug Command succesfull
2016-01-04 21:38:04.4399 Debug 06-63
2016-01-04 21:38:04.9419 Debug 55
2016-01-04 21:38:04.9419 Debug Command succesfull
"2016-01-04 21:38:04.9442 Info HomeAutomation.X10 A10 - Status.Level 0"
2016-01-04 21:38:05.7634 Debug 5A-02-00-6F
2016-01-04 21:38:05.7639 Debug PLCRX: 5A-02-00-6F
2016-01-04 21:38:05.7639 Debug FNMAP: 00
2016-01-04 21:38:05.7649 Debug DATA : 6F
2016-01-04 21:38:05.7649 Debug       0) Address = A10
2016-01-04 21:38:06.0093 Debug 5A-02-01-63
2016-01-04 21:38:06.0098 Debug PLCRX: 5A-02-01-63
2016-01-04 21:38:06.0098 Debug FNMAP: 01
2016-01-04 21:38:06.0098 Debug DATA : 63
2016-01-04 21:38:06.0110 Debug       0) House code = A
2016-01-04 21:38:06.0126 Debug       0)    Command = Off
"2016-01-04 21:38:06.0126 Info HomeAutomation.X10 A10 - Status.Level 0"
2016-01-04 21:38:10.0143 Debug 04-6F
"2016-01-04 21:38:10.2347 Info HGIC:192_168_1_120.HomeAutomation.ZWave 4 Binary Switch Meter.Watts 0.0"
"2016-01-04 21:38:10.2588 Info HomeAutomation.X10 A1 X10 Module Meter.Watts 0.0"
"2016-01-04 21:38:10.3508 Info HomeAutomation.X10 A2 X10 Module Meter.Watts 0.0"
"2016-01-04 21:38:10.4198 Info HomeAutomation.X10 A5 X10 Module Meter.Watts 0.0"
"2016-01-04 21:38:10.4955 Info HomeAutomation.X10 A6 X10 Module Meter.Watts 0.0"
"2016-01-04 21:38:10.5806 Info HomeAutomation.X10 A8 X10 Module Meter.Watts 40.09"
"2016-01-04 21:38:10.6675 Info HomeAutomation.X10 A9 X10 Module Meter.Watts 0.0"
"2016-01-04 21:38:10.7498 Info HomeAutomation.X10 A10 X10 Module Meter.Watts 0.0"
"2016-01-04 21:38:10.8218 Info HomeAutomation.X10 A11 X10 Module Meter.Watts 24.75"
"2016-01-04 21:38:10.9144 Info HomeAutomation.X10 A12 X10 Module Meter.Watts 0.0"
"2016-01-04 21:38:11.0158 Info HomeAutomation.X10 A13 X10 Module Meter.Watts 0.0"
2016-01-04 21:38:11.0917 Debug 55
2016-01-04 21:38:11.0917 Debug Command succesfull
2016-01-04 21:38:11.0942 Debug 06-62
"2016-01-04 21:38:11.1118 Info HomeAutomation.X10 A14 X10 Module Meter.Watts 0.0"
"2016-01-04 21:38:11.1971 Info HomeAutomation.X10 A15 X10 Module Meter.Watts 100.12"
"2016-01-04 21:38:11.2825 Info HomeAutomation.X10 D1 X10 Module Meter.Watts 50.01"
"2016-01-04 21:38:11.3695 Info HomeAutomation.X10 D2 X10 Module Meter.Watts 0.0"
"2016-01-04 21:38:11.4533 Info HomeAutomation.X10 D4 X10 Module Meter.Watts 0.0"
"2016-01-04 21:38:11.5397 Info HomeAutomation.X10 D5 X10 Module Meter.Watts 0.0"
2016-01-04 21:38:11.6037 Debug 55
2016-01-04 21:38:11.6037 Debug Command succesfull
"2016-01-04 21:38:11.6058 Info HomeAutomation.X10 A10 - Status.Level 1"
"2016-01-04 21:38:11.6311 Info HomeAutomation.HomeGenie.Automation 1066 Automation Program Program.Status Idle"
"2016-01-04 21:38:11.7484 Info HomeAutomation.X10 D6 X10 Module Meter.Watts 11.91"
"2016-01-04 21:38:11.8356 Info WebServiceGateway 192.168.1.103 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Interfaces.List/ [CLOSED AFTER 0,007 seconds]"
"2016-01-04 21:38:11.8282 Info WebServiceGateway 192.168.1.103 HTTP GET 200 /api/HomeAutomation.HomeGenie/Config/Interfaces.List/ [OPEN]"
"2016-01-04 21:38:11.8410 Info HomeAutomation.X10 D7 X10 Module Meter.Watts 0.0"
"2016-01-04 21:38:11.9445 Info HomeAutomation.X10 E1 X10 Module Meter.Watts 0.0"
"2016-01-04 21:38:12.0020 Info HomeAutomation.X10 E2 X10 Module Meter.Watts 16.93"
"2016-01-04 21:38:12.1176 Info HomeAutomation.X10 E8 X10 Module Meter.Watts 0.0"
"2016-01-04 21:38:12.2085 Info HomeAutomation.ZWave 4 Binary Switch Meter.Watts 40.17"
"2016-01-04 21:38:12.3253 Info HomeAutomation.ZWave 5 Binary Switch Meter.Watts 0.0"
2016-01-04 21:38:12.4053 Debug 5A-02-00-6F
2016-01-04 21:38:12.4181 Debug PLCRX: 5A-02-00-6F
2016-01-04 21:38:12.4181 Debug FNMAP: 00
2016-01-04 21:38:12.4188 Debug DATA : 6F
2016-01-04 21:38:12.4202 Debug       0) Address = A10
"2016-01-04 21:38:12.4539 Info HomeAutomation.ZWave 9 Multilevel Switch Meter.Watts 8.13"
"2016-01-04 21:38:12.5300 Info HomeAutomation.ZWave 10 Multilevel Switch Meter.Watts 7.77"
2016-01-04 21:38:12.6719 Debug 5A-02-01-62
2016-01-04 21:38:12.6719 Debug PLCRX: 5A-02-01-62
2016-01-04 21:38:12.6731 Debug FNMAP: 01
2016-01-04 21:38:12.6737 Debug DATA : 62
2016-01-04 21:38:12.6737 Debug       0) House code = A
2016-01-04 21:38:12.6751 Debug       0)    Command = On
"2016-01-04 21:38:12.6795 Info HomeAutomation.X10 A10 - Status.Level 1"

Does anyone have an idea what is happening here?

Cheers
Pim

[bkenobi]

Do you have a repeater in your setup?  It looks to me like HG is reporting that it sends the command once and then it receives a PLC command for the same thing.  I have a repeater, but it sends a boosted signal during the second half of the doublet rather than sending the code a second time after the line is clear.

This could be related to HG, but to me it looks more likely this is something related to your hardware (or how HG is interacting with it).

[pim555]

Thanks.

I do indeed have a phase coupler, Xanura FKX40. I have had this phase coupler for the last few years but only noticed described issues recently. This phase coupler amplifies received signals on a specific phase onto all 3 phases. I guess this means it repeats the signal on the receiving phase.

I cannot really reprogram this device (to experiment) as I need a PMIX35 device. Need to send 2xON, or 2xBright/DIM to configure but these code sequences are only available with a device like PMIX35 or I would need to hack the xtenlib (not even sure if that would be possible).

Would you happen to know if this is possible in any other way?

Regards
Pim

[bkenobi]

If I read correctly, you are saying that the repeater always sends 2x the command for it to work.  If so, then that would make sense since that's what we see in your log.  I use the XTB-IIR in my setup and it works differently.  It watches for incoming commands on the mains and when it determines that the first half of the doublet is valid, it repeats at a higher power over top of the second half of the doublet.  So it does not send the command a second time, it only boosts the second half (which is a repeat of the original command and is how X10 PLC standard is set up).  I know nothing about your repeater but it sounds like that could be the cause of your issues.

This forum is aimed at HG.  It sounds like you have a hardware issue to me.  If there is no forum for Xanura products, you could try asking your hardware related question on the x10 forums.  There's lots of knowledgeable people there that might have some good suggestions.  But, I don't know for sure this is a hardware issue.  I'm 75% sure it is though.