Issue with test switch from Ezlo bridge

Plugins & Plugin Development Reactor
#1

Hi once again, I am having issues with a condition. The device testswitch 20021 which is triggering once but when triggered again does not get picked up by reactor. If i reset the reactor sensor it fire but no retruggers

The below logic summary was taken when testswitch status was 1,
I updated to stable about 2 hours ago.
Ktchen main auto group which has same logic is working correctly.

*************************************************** REACTOR LOGIC SUMMARY REPORT ***************************************************
   Version: 3.9develop-20355.2120 config 20263 cdata 20045 ui 20355 pluginDevice 10 LuaXP 1.0.2enh
    System: openLuup version 200629 on Linux localhost 4.9.76 #1 SMP PREEMPT Wed Jan 16 09:21:08 CST 2019 armv8l GNU/Linux; in ./; loadtime 1589041607/1608656555; systemReady 1608656560; ALTUI v2.52
       Env: Lua 5.1; JSON dkjson 2.5; UnsafeLua=nil/2
Local time: 2020-12-22T17:26:37+0000; DST=0; Greenwich, England UNITED KINGDOM; formats %d/%m/%Y %H:%M:%S
House mode: plugin 1; system 1; tracking on
  Sun data: {"source":"int","civdawn":1608621582,"nautdawn":1608619039,"sunset":1608652557,"nautdusk":1608657466,"stamp":2020357,"latitude":50.77,"astrodusk":1608659874,"longitude":0.29,"civdusk":1608654923,"astrodawn":1608616631,"sunrise":1608623948}
  Geofence: not running
        RS: 1608395042,1608407227,1608407239,1608650874,1608650888,1608651591,1608652852,1608656367,1608656389,1608656555
        NS: 1594479300:D,1594479511:U,1594485541:D,1594485600:U,1598327160:D,1598376660:U,1599008940:D,1599009180:U,1600292760:D,1600293121:U
************************************************************************************************************************************
Reactor Sensor 3 (#14)
    Version 20045.122 2020-12-22 16:42:15
    Message/status: 
    Variable/expressions
       0: loadlevelkit             getstate( 10043, "urn:upnp-org:serviceId:Dimming1", "LoadLevelLast" ) [last "50"(string)]
       1: loadlevelpen             getstate( 10082, "urn:upnp-org:serviceId:Dimming1", "LoadLevelLast" ) [last "50"(string)]
       2: loadlevelcab             getstate( 10041, "urn:upnp-org:serviceId:Dimming1", "LoadLevelLast" ) [last "46"(string)]
       3: loadlevellounge1         getstate( 10008, "urn:upnp-org:serviceId:Dimming1", "LoadLevelLast" ) [last "5"(string)]
       4: loadlevellounge2         getstate( 10031, "urn:upnp-org:serviceId:Dimming1", "LoadLevelLast" ) [last "20"(string)]
       5: loadlevelwall            getstate( 10019, "urn:upnp-org:serviceId:Dimming1", "LoadLevelLast" ) [last "100"(string)]
    Condition group "Auto Levels" (NUL)  false as of n/a <root>
      Z-F-group "monitor luup reload" (AND)  false as of 17:02:37 <grppypqpw6>
      |     &-F-reload  [true => false at 17:02:37; F/F as of 17:02:37/17:02:37] <condpxw4kq6>
      Z-T-group "is night" (AND)  TRUE as of 16:47:48 <grppys1fa3>
      |     &-T-sun bet sunset-40,sunrise+0 [1608657930 => 1608657982 at 17:26:22; T/T as of 16:47:48/16:47:48] <condpxw2vss>
      |     &-T-service Door sensor (10166) urn:upnp-org:serviceId:SwitchPower1/Status = 0 [0 at 16:47:48; T/T as of 16:47:48/16:47:48] <condq8mwlx8>
      Z-T-group "kit main auto" (AND)  TRUE as of 17:15:29 <grppxw08hq>
      |     &-T-group "grppxw2h1n" (OR)  TRUE as of 16:47:48 <grppxw2h1n>
      |     |     |-T-grpstate (self) (-1) is night (grppys1fa3) istrue [true at 16:47:48; T/T as of 16:47:48/16:47:48] <condpys15la>
      |     |     |-F-service Kitchen Main (10043) urn:upnp-org:serviceId:SwitchPower1/Status = 1 [1 => 0 at 17:26:22; F/F as of 17:26:22/17:26:22] <condpxw3vg5>
      |     &-T-service motion kitchen (10182) urn:micasaverde-com:serviceId:SecuritySensor1/Tripped istrue  after grppxw2h1n; output follow, delay reset for 180s [1 => 0 at 17:24:51; F/T as of 17:24:51/17:15:29] <condpypr5ww>
      Z-F-group "kit pendant auto" (AND)  false as of 16:47:48 <grppypn9cs>
      |     &-F-service Kitchen Pendants (10082) urn:upnp-org:serviceId:SwitchPower1/Status = 1 [0 at 16:47:48; F/F as of 16:47:48/16:47:48] <condpypoe3z>
      |     &-F-service motion kitchen (10182) urn:micasaverde-com:serviceId:SecuritySensor1/Tripped = 1 after condpypoe3z; output follow, delay reset for 180s [1 => 0 at 17:24:51; F/F as of 17:24:51/16:47:48] <condpyptpu8>
      Z-F-group "kit cab auto" (AND)  false as of 16:47:48 <grppypo1gi>
      |     &-F-service kitchen Under (10041) urn:upnp-org:serviceId:SwitchPower1/Status = 1 [0 at 16:47:48; F/F as of 16:47:48/16:47:48] <condpypof5g>
      |     &-F-service motion kitchen (10182) urn:micasaverde-com:serviceId:SecuritySensor1/Tripped = 1 after condpypof5g; output follow, delay reset for 180s [1 => 0 at 17:24:51; F/F as of 17:24:51/16:47:48] <condpypui5c>
      Z-X-group "lounge 1 auto" (AND)  false as of n/a DISABLED <grppyrfotb>
      |     &-?-service Lounge 1 (10008) urn:upnp-org:serviceId:SwitchPower1/Status = 1 [nil at n/a; F/F as of n/a/n/a] <condpyrgox3>
      |     &-?-service motion rear pir (10186) urn:micasaverde-com:serviceId:SecuritySensor1/Tripped = 1 after condpyrgox3; output follow, delay reset for 180s [nil at n/a; F/F as of n/a/n/a] <condpyrgq1p>
      Z-T-group "lounge 2 on" (AND)  TRUE as of 17:26:22 <grppyrz6h6>
      |     &-T-group "grpramakax" (OR)  TRUE as of 16:47:48 <grpramakax>
      |     |     |-T-grpstate (self) (-1) is night (grppys1fa3) istrue [true at 16:47:48; T/T as of 16:47:48/16:47:48] <condraipdos>
      |     |     |-T-service Lounge 2 (10031) urn:upnp-org:serviceId:SwitchPower1/Status istrue  [0 => 1 at 17:26:22; T/T as of 17:26:22/17:26:22] <condraiqvfa>
      |     &-T-service TestSwitch (20021) urn:upnp-org:serviceId:SwitchPower1/Status istrue ; output follow, delay reset for 600s [0 => 1 at 17:26:22; T/T as of 17:26:22/17:26:22] <condpyrzjnk>
      Z-X-group "wall auto" (AND)  false as of n/a DISABLED <grppysg0nr>
      |     &-?-service Wall (10019) urn:upnp-org:serviceId:SwitchPower1/Status = 1 [nil at n/a; F/F as of n/a/n/a] <condpysg2zk>
      |     &-?-service motion rear pir (10186) urn:micasaverde-com:serviceId:SecuritySensor1/Tripped = 1 after condpysg2zk; output follow, delay reset for 180s [nil at n/a; F/F as of n/a/n/a] <condpysg463>
    Activity grppypo1gi.false
        Device kitchen Under (10041) action urn:upnp-org:serviceId:Dimming1/SetLoadLevelTarget( newLoadlevelTarget="0" )
        Run Lua:
             1: luup.variable_set("urn:upnp-org:serviceId:Dimming1", "LoadLevelLast", "50", 10041)
    Activity grppxw08hq.false
        Device Kitchen Main (10043) action urn:upnp-org:serviceId:Dimming1/SetLoadLevelTarget( newLoadlevelTarget="0" )
        Run Lua:
             1: luup.variable_set("urn:upnp-org:serviceId:Dimming1", "LoadLevelLast", "50", 10043)
    Activity grppyrfotb.true
        Device Lounge 1 (10008) action urn:upnp-org:serviceId:Dimming1/SetLoadLevelTarget( newLoadlevelTarget="{loadlevellounge1}" )
    Activity grppxw08hq.true
        Device Kitchen Main (10043) action urn:upnp-org:serviceId:Dimming1/SetLoadLevelTarget( newLoadlevelTarget="{loadlevelkit}" )
    Activity grppypn9cs.false
        Device Kitchen Pendants (10082) action urn:upnp-org:serviceId:Dimming1/SetLoadLevelTarget( newLoadlevelTarget="0" )
        Run Lua:
             1: luup.variable_set("urn:upnp-org:serviceId:Dimming1", "LoadLevelLast", "50", 10082)
    Activity grppyrfotb.false
        Device Lounge 1 (10008) action urn:upnp-org:serviceId:Dimming1/SetLoadLevelTarget( newLoadlevelTarget="0" )
        Run Lua:
             1: luup.variable_set("urn:upnp-org:serviceId:Dimming1", "LoadLevelLast", "20", 10008)
    Activity grppyrz6h6.false
        Device Lounge 2 (10031) action urn:upnp-org:serviceId:Dimming1/SetLoadLevelTarget( newLoadlevelTarget="0" )
        Run Lua:
             1: luup.variable_set("urn:upnp-org:serviceId:Dimming1", "LoadLevelLast", "20", 10031)
    Activity grppypqpw6.true
        Notify method SM nid 2: message "Luup reload"; recipient="sidstone909@gmail.com"; index="1"; subject="luup reload OpenLuup"; SMTPServer="smtp.gmail.com"; SMTPPort="465"; SMTPSender="thecid910@gmail.com"; SMTPDefaultRecipient="thecid910@gmail.com"; SMTPDefaultSubject="Reactor notification"; SMTPUsername="thecid910@gmail.com"; SMTPPassword="*"; SSL opt {"verify":"none","mode":"client","protocol":"any"}
    Activity grppyrz6h6.true
        Device Lounge 2 (10031) action urn:upnp-org:serviceId:Dimming1/SetLoadLevelTarget( newLoadlevelTarget="{loadlevellounge2}" )
    Activity grppysg0nr.false
        Device Wall (10019) action urn:upnp-org:serviceId:Dimming1/SetLoadLevelTarget( newLoadlevelTarget="0" )
        Run Lua:
             1: luup.variable_set("urn:upnp-org:serviceId:Dimming1", "LoadLevelLast", "30", 10019)
    Activity grppypo1gi.true
        Device kitchen Under (10041) action urn:upnp-org:serviceId:Dimming1/SetLoadLevelTarget( newLoadlevelTarget="{loadlevelcab}" )
    Activity grppysg0nr.true
        Device Wall (10019) action urn:upnp-org:serviceId:Dimming1/SetLoadLevelTarget( newLoadlevelTarget="{loadlevelwall}" )
    Activity grppypn9cs.true
        Device Kitchen Pendants (10082) action urn:upnp-org:serviceId:Dimming1/SetLoadLevelTarget( newLoadlevelTarget="{loadlevelpen}" )
    Events
        2020-12-22 17:02:42.252: Starting "grppypqpw6.true" group 1 at step 1
        2020-12-22 17:02:43.432: Activity "grppypqpw6.true" finished in 6.385999917984s
        2020-12-22 17:02:43.433: Stopping activity "grppypqpw6.true"
        2020-12-22 17:09:36.218: Sensor update starting
        2020-12-22 17:09:36.227: Condition condpyrzjnk test state changed from false to true
        2020-12-22 17:09:36.241: Sensor update completed; 0.023s
        2020-12-22 17:15:29.035: Device motion kitchen (#10182) urn:micasaverde-com:serviceId:SecuritySensor1/Tripped changed from "0" to "1"
        2020-12-22 17:15:29.035: Sensor update starting
        2020-12-22 17:15:29.044: Condition condpypr5ww test state changed from false to true
        2020-12-22 17:15:29.044: Condition condpypr5ww evaluation state changed from false to true
        2020-12-22 17:15:29.044: Group kit main auto test state changed from false to true
        2020-12-22 17:15:29.045: Group kit main auto evaluation state changed from false to true
        2020-12-22 17:15:29.046: Condition condpyptpu8 test state changed from false to true
        2020-12-22 17:15:29.046: Condition condpyptpu8 predecessor condition restriction not met
        2020-12-22 17:15:29.047: Condition condpypui5c test state changed from false to true
        2020-12-22 17:15:29.047: Condition condpypui5c predecessor condition restriction not met
        2020-12-22 17:15:29.048: Condition condpyrzjnk test state changed from true to false
        2020-12-22 17:15:29.048: Condition condpyrzjnk evaluation state reset delayed 600 more seconds
        2020-12-22 17:15:29.061: Preparing kit main auto.true (grppxw08hq.true) activity
        2020-12-22 17:15:29.063: Launching scene/activity "grppxw08hq.true"
        2020-12-22 17:15:29.065: Starting "grppxw08hq.true" group 1 at step 1
        2020-12-22 17:15:29.069: Activity "grppxw08hq.true" finished in 0.0060000419616699s
        2020-12-22 17:15:29.070: Stopping activity "grppxw08hq.true"
        2020-12-22 17:15:29.076: Sensor update completed; 0.041s
        2020-12-22 17:15:29.643: Device Kitchen Main (#10043) urn:upnp-org:serviceId:SwitchPower1/Status changed from "0" to "1"
        2020-12-22 17:15:29.644: Sensor update starting
        2020-12-22 17:15:29.650: Condition condpxw3vg5 test state changed from false to true
        2020-12-22 17:15:29.650: Condition condpxw3vg5 evaluation state changed from false to true
        2020-12-22 17:15:29.651: Condition condpyptpu8 predecessor condition restriction not met
        2020-12-22 17:15:29.652: Condition condpypui5c predecessor condition restriction not met
        2020-12-22 17:15:29.652: Condition condpyrzjnk evaluation state reset delayed 600 more seconds
        2020-12-22 17:15:29.663: Sensor update completed; 0.019s
        2020-12-22 17:19:04.828: Device motion kitchen (#10182) urn:micasaverde-com:serviceId:SecuritySensor1/Tripped changed from "1" to "0"
        2020-12-22 17:19:04.829: Sensor update starting
        2020-12-22 17:19:04.836: Condition condpypr5ww test state changed from true to false
        2020-12-22 17:19:04.837: Condition condpypr5ww evaluation state reset delayed 180 more seconds
        2020-12-22 17:19:04.838: Condition condpyptpu8 test state changed from true to false
        2020-12-22 17:19:04.839: Condition condpypui5c test state changed from true to false
        2020-12-22 17:19:04.839: Condition condpyrzjnk evaluation state reset delayed 385 more seconds
        2020-12-22 17:19:04.851: Sensor update completed; 0.022s
        2020-12-22 17:21:43.156: Device motion kitchen (#10182) urn:micasaverde-com:serviceId:SecuritySensor1/Tripped changed from "0" to "1"
        2020-12-22 17:21:43.157: Sensor update starting
        2020-12-22 17:21:43.164: Condition condpypr5ww test state changed from false to true
        2020-12-22 17:21:43.165: Condition condpyptpu8 test state changed from false to true
        2020-12-22 17:21:43.166: Condition condpyptpu8 predecessor condition restriction not met
        2020-12-22 17:21:43.166: Condition condpypui5c test state changed from false to true
        2020-12-22 17:21:43.167: Condition condpypui5c predecessor condition restriction not met
        2020-12-22 17:21:43.167: Condition condpyrzjnk evaluation state reset delayed 226 more seconds
        2020-12-22 17:21:43.178: Sensor update completed; 0.021s
        2020-12-22 17:24:51.176: Device motion kitchen (#10182) urn:micasaverde-com:serviceId:SecuritySensor1/Tripped changed from "1" to "0"
        2020-12-22 17:24:51.177: Sensor update starting
        2020-12-22 17:24:51.187: Condition condpypr5ww test state changed from true to false
        2020-12-22 17:24:51.188: Condition condpypr5ww evaluation state reset delayed 180 more seconds
        2020-12-22 17:24:51.189: Condition condpyptpu8 test state changed from true to false
        2020-12-22 17:24:51.190: Condition condpypui5c test state changed from true to false
        2020-12-22 17:24:51.190: Condition condpyrzjnk evaluation state reset delayed 38 more seconds
        2020-12-22 17:24:51.209: Sensor update completed; 0.032s
        2020-12-22 17:25:29.366: Sensor update starting
        2020-12-22 17:25:29.383: Condition condpypr5ww evaluation state reset delayed 142 more seconds
        2020-12-22 17:25:29.384: Condition condpyrzjnk reset delay has now expired
        2020-12-22 17:25:29.385: Condition condpyrzjnk evaluation state changed from true to false
        2020-12-22 17:25:29.385: Group lounge 2 on test state changed from true to false
        2020-12-22 17:25:29.386: Group lounge 2 on evaluation state changed from true to false
        2020-12-22 17:25:29.401: Preparing lounge 2 on.false (grppyrz6h6.false) activity
        2020-12-22 17:25:29.403: Launching scene/activity "grppyrz6h6.false"
        2020-12-22 17:25:29.405: Starting "grppyrz6h6.false" group 1 at step 1
        2020-12-22 17:25:29.412: Activity "grppyrz6h6.false" finished in 0.0079998970031738s
        2020-12-22 17:25:29.412: Stopping activity "grppyrz6h6.false"
        2020-12-22 17:25:29.415: Sensor update completed; 0.050s
        2020-12-22 17:25:29.523: Device Lounge 2 (#10031) urn:upnp-org:serviceId:Dimming1/LoadLevelLast changed from "20" to "20"
        2020-12-22 17:25:29.525: Sensor update starting
        2020-12-22 17:25:29.540: Condition condpypr5ww evaluation state reset delayed 142 more seconds
        2020-12-22 17:25:29.558: Sensor update completed; 0.033s
        2020-12-22 17:25:30.150: Device Lounge 2 (#10031) urn:upnp-org:serviceId:SwitchPower1/Status changed from "1" to "0"
        2020-12-22 17:25:30.151: Sensor update starting
        2020-12-22 17:25:30.157: Condition condpypr5ww evaluation state reset delayed 141 more seconds
        2020-12-22 17:25:30.158: Condition condraiqvfa test state changed from true to false
        2020-12-22 17:25:30.159: Condition condraiqvfa evaluation state changed from true to false
        2020-12-22 17:25:30.169: Sensor update completed; 0.017s
        2020-12-22 17:26:22.181: Device Kitchen Main (#10043) urn:upnp-org:serviceId:SwitchPower1/Status changed from "1" to "0"
        2020-12-22 17:26:22.182: Sensor update starting
        2020-12-22 17:26:22.194: Condition condpxw3vg5 test state changed from true to false
        2020-12-22 17:26:22.195: Condition condpxw3vg5 evaluation state changed from true to false
        2020-12-22 17:26:22.195: Condition condpypr5ww evaluation state reset delayed 89 more seconds
        2020-12-22 17:26:22.196: Condition condpyrzjnk test state changed from false to true
        2020-12-22 17:26:22.197: Condition condpyrzjnk evaluation state changed from false to true
        2020-12-22 17:26:22.197: Group lounge 2 on test state changed from false to true
        2020-12-22 17:26:22.198: Group lounge 2 on evaluation state changed from false to true
        2020-12-22 17:26:22.209: Preparing lounge 2 on.true (grppyrz6h6.true) activity
        2020-12-22 17:26:22.211: Launching scene/activity "grppyrz6h6.true"
        2020-12-22 17:26:22.213: Starting "grppyrz6h6.true" group 1 at step 1
        2020-12-22 17:26:22.220: Activity "grppyrz6h6.true" finished in 0.0090000629425049s
        2020-12-22 17:26:22.221: Stopping activity "grppyrz6h6.true"
        2020-12-22 17:26:22.228: Sensor update completed; 0.046s
        2020-12-22 17:26:22.776: Device Lounge 2 (#10031) urn:upnp-org:serviceId:SwitchPower1/Status changed from "0" to "1"
        2020-12-22 17:26:22.778: Sensor update starting
        2020-12-22 17:26:22.785: Condition condpypr5ww evaluation state reset delayed 89 more seconds
        2020-12-22 17:26:22.786: Condition condraiqvfa test state changed from false to true
        2020-12-22 17:26:22.787: Condition condraiqvfa evaluation state changed from false to true
        2020-12-22 17:26:22.800: Sensor update completed; 0.022s
    Devices
        kitchen Under (10041) urn:schemas-upnp-org:device:DimmableLight:1 (2/0); parent 1; plugin -; mfg  model ; dev D_DimmableLight1.xml impl X
        Kitchen Main (10043) urn:schemas-upnp-org:device:DimmableLight:1 (2/0); parent 1; plugin -; mfg  model ; dev D_DimmableLight1.xml impl X
        TestSwitch (20021) urn:schemas-upnp-org:device:BinaryLight:1 (3/1); parent 24; plugin -; mfg  model ; dev D_BinaryLight1.xml impl X
        VeraBridge (5) VeraBridge (1/0); parent 0; plugin -; mfg akbooer model ; dev D_VeraBridge.xml impl I_VeraBridge.xml
        Zigbee Network (10002) urn:schemas-micasaverde-com:device:ZigbeeNetwork:1 (0/0); parent 5; plugin -; mfg Mi Casa Verde model GC100; dev D_ZigbeeNetwork.xml impl X
        motion kitchen (10182) urn:schemas-micasaverde-com:device:MotionSensor:1 (4/3); parent 5; plugin -; mfg  model ; dev D_MotionSensor1.xml impl X
        motion rear pir (10186) urn:schemas-micasaverde-com:device:MotionSensor:1 (4/3); parent 5; plugin -; mfg  model ; dev D_MotionSensor1.xml impl X
        Lounge 1 (10008) urn:schemas-upnp-org:device:DimmableLight:1 (2/0); parent 1; plugin -; mfg  model ; dev D_DimmableLight1.xml impl X
        Door sensor (10166) urn:schemas-micasaverde-com:device:DoorSensor:1 (4/1); parent 10002; plugin -; mfg  model ; dev D_DoorSensor1.xml impl X
        Lounge 2 (10031) urn:schemas-upnp-org:device:DimmableLight:1 (2/0); parent 1; plugin -; mfg  model ; dev D_DimmableLight1.xml impl X
        Wall (10019) urn:schemas-upnp-org:device:DimmableLight:1 (2/0); parent 1; plugin -; mfg  model ; dev D_DimmableLight1.xml impl X
        Ezlo Bridge (24) urn:schemas-rboer-com:device:EzloBridge:1 (1/0); parent 0; plugin -; mfg ReneBoer model ; dev D_EzloBridge.xml impl I_EzloBridge.xml
        ZWave (1) urn:schemas-micasaverde-com:device:ZWaveNetwork:1 (19/0); parent 5; plugin -; mfg Mi Casa Verde model GC100; dev D_ZWaveNetwork.xml impl X
        Kitchen Pendants (10082) urn:schemas-upnp-org:device:DimmableLight:1 (2/0); parent 1; plugin -; mfg  model ; dev D_DimmableLight1.xml impl X
    Watches
        Device #10182 motion kitchen service urn:micasaverde-com:serviceId:SecuritySensor1 variable Tripped
        Device #20021 TestSwitch service urn:upnp-org:serviceId:SwitchPower1 variable Status
        Device #10019 Wall service urn:upnp-org:serviceId:Dimming1 variable LoadLevelLast
        Device #10043 Kitchen Main service urn:upnp-org:serviceId:Dimming1 variable LoadLevelLast
        Device #10041 kitchen Under service urn:upnp-org:serviceId:Dimming1 variable LoadLevelLast
        Device #10082 Kitchen Pendants service urn:upnp-org:serviceId:SwitchPower1 variable Status
        Device #14 Reactor Sensor 3 service urn:toggledbits-com:serviceId:ReactorSensor variable TestHouseMode
        Device #14 Reactor Sensor 3 service urn:toggledbits-com:serviceId:ReactorGroup variable GroupStatus_grppys1fa3
        Device #10041 kitchen Under service urn:upnp-org:serviceId:SwitchPower1 variable Status
        Device #10043 Kitchen Main service urn:upnp-org:serviceId:SwitchPower1 variable Status
        Device #10031 Lounge 2 service urn:upnp-org:serviceId:SwitchPower1 variable Status
        Device #10166 Door sensor service urn:upnp-org:serviceId:SwitchPower1 variable Status
        Device #10031 Lounge 2 service urn:upnp-org:serviceId:Dimming1 variable LoadLevelLast
        Device #10082 Kitchen Pendants service urn:upnp-org:serviceId:Dimming1 variable LoadLevelLast
        Device #14 Reactor Sensor 3 service urn:toggledbits-com:serviceId:ReactorSensor variable cdata
        Device #10008 Lounge 1 service urn:upnp-org:serviceId:Dimming1 variable LoadLevelLast
        Device #14 Reactor Sensor 3 service urn:toggledbits-com:serviceId:ReactorSensor variable TestTime
    Special Configuration
        Retrigger = 0

I also noticed that all AltUI device icons have disappered and been replaced with Default z icon as below

Screenshot_20201222-173621
Screenshot_20201222-1736211920Ɨ1080 213 KB

#2

Can you be more clear about what your expectation is there? Iā€™m assuming you understand that the only way to retrigger a condition is for it to transition through its opposite state? Meaning, once it goes true, it will not go true again until it has reset to false. There is no ā€œretriggeringā€ of the true while it remains true. Thereā€™s nothing in the event log here to indicate that it ever went false (or changed at all in the period covered by these events), so Iā€™m not really sure what Iā€™m supposed to be looking for.

In contrast, I can see ā€œmotion kitchenā€ transitioning back and forth in the log.

Note sure what your icon issue is. Is this Android Firefox mobile again?

EDIT: Also just noticed your TestSwitch condition does not have a sequence restriction that ā€œkitch main autoā€'s device does have. Not sure what all this is doing, but that may affect results as wellā€¦

#3

Yes i understand. the switch goes status 1, the status 0

but i get no trigger on the reactor condition. or if i reset the reactor sensor, the device when status 1, sets the condition true, this is then held true by delay reset for 600 second. After 5 seconds switch goes status 0, if retriggered to status 1 the delay does not get reset. When the delay runs out the condition will not go true if status is the set to 1 from 0.

It was working with no issues yesterday but this evening it failed.

Yes the icon issue is firefox android again, but maybe altui or openluup issue everthing works so i can wait till every one catches up with jquery and bootstraps

#4

OK, but this log is not showing me a problem. The switch itself is remaining true, so there is no reset, so the delay period never begins during the period of these events. Also know that I put the entire system through a series of automated tests that test exactly these kinds of logic thingsā€¦ all the delays, all the resets, all the pulses, everything on and off at odd times, and even reloads in the middle of timing, etc. I also use this system and these features in my own house pretty extensively. If thereā€™s a problem here, Iā€™ll be surprised. Iā€™m not saying itā€™s not a possibility, but at this point, youā€™re going to have to do more to prove to me, literally show me, that itā€™s not working and isnā€™t a logic problem.

Did you see my comment about TestSwitch not having the sequence restriction that the ā€œkitch mainā€ one you compare it to seems to have? Could that be the issue?

#5

No thatā€™s not issue as i removed any restrictions to simplify.
here is logic the device is stuck. The switch is in on position which i just set from off. The condition did not update

*************************************************** REACTOR LOGIC SUMMARY REPORT ***************************************************
   Version: 3.9develop-20355.2120 config 20263 cdata 20045 ui 20355 pluginDevice 10 LuaXP 1.0.2enh
    System: openLuup version 200522 on Linux localhost 4.9.76 #1 SMP PREEMPT Wed Jan 16 09:21:08 CST 2019 armv8l GNU/Linux; in ./; loadtime 1589041607/1608667448; systemReady 1608667453; ALTUI v2.52
       Env: Lua 5.1; JSON dkjson 2.5; UnsafeLua=nil/2
Local time: 2020-12-22T20:24:51+0000; DST=0; Greenwich, England UNITED KINGDOM; formats %d/%m/%Y %H:%M:%S
House mode: plugin 1; system 1; tracking on
  Sun data: {"source":"int","civdawn":1608621582,"nautdawn":1608619039,"sunset":1608652557,"nautdusk":1608657466,"stamp":2020357,"latitude":50.77,"astrodusk":1608659874,"longitude":0.29,"civdusk":1608654923,"astrodawn":1608616631,"sunrise":1608623948}
  Geofence: not running
        RS: 1608650888,1608651591,1608652852,1608656367,1608656389,1608656555,1608659540,1608666432,1608667113,1608667448
        NS: 1594479300:D,1594479511:U,1594485541:D,1594485600:U,1598327160:D,1598376660:U,1599008940:D,1599009180:U,1600292760:D,1600293121:U
************************************************************************************************************************************
Reactor Sensor 3 (#14)
    Version 20045.125 2020-12-22 19:50:42
    Message/status: 
    Variable/expressions
       0: loadlevelkit             getstate( 10043, "urn:upnp-org:serviceId:Dimming1", "LoadLevelLast" ) [last "50"(string)]
       1: loadlevelpen             getstate( 10082, "urn:upnp-org:serviceId:Dimming1", "LoadLevelLast" ) [last "100"(string)]
       2: loadlevelcab             getstate( 10041, "urn:upnp-org:serviceId:Dimming1", "LoadLevelLast" ) [last "46"(string)]
       3: loadlevellounge1         getstate( 10008, "urn:upnp-org:serviceId:Dimming1", "LoadLevelLast" ) [last "5"(string)]
       4: loadlevellounge2         getstate( 10031, "urn:upnp-org:serviceId:Dimming1", "LoadLevelLast" ) [last "20"(string)]
       5: loadlevelwall            getstate( 10019, "urn:upnp-org:serviceId:Dimming1", "LoadLevelLast" ) [last "100"(string)]
    Condition group "Auto Levels" (NUL)  false as of n/a <root>
      Z-F-group "monitor luup reload" (AND)  false as of 20:04:09 <grppypqpw6>
      |     &-F-reload  [true => false at 20:04:09; F/F as of 20:04:09/20:04:09] <condpxw4kq6>
      Z-T-group "is night" (AND)  TRUE as of 16:47:48 <grppys1fa3>
      |     &-T-sun bet sunset-40,sunrise+0 [1608667114 => 1608667449 at 20:04:09; T/T as of 16:47:48/16:47:48] <condpxw2vss>
      |     &-T-service Door sensor (10166) urn:upnp-org:serviceId:SwitchPower1/Status = 0 [0 at 16:47:48; T/T as of 16:47:48/16:47:48] <condq8mwlx8>
      Z-F-group "kit main auto" (AND)  false as of 19:44:19 <grppxw08hq>
      |     &-T-group "grppxw2h1n" (OR)  TRUE as of 16:47:48 <grppxw2h1n>
      |     |     |-T-grpstate (self) (-1) is night (grppys1fa3) istrue [true at 16:47:48; T/T as of 16:47:48/16:47:48] <condpys15la>
      |     |     |-F-service Kitchen Main (10043) urn:upnp-org:serviceId:SwitchPower1/Status = 1 [1 => 0 at 19:26:49; F/F as of 19:26:49/19:26:49] <condpxw3vg5>
      |     &-F-service motion kitchen (10182) urn:micasaverde-com:serviceId:SecuritySensor1/Tripped istrue  after grppxw2h1n; output follow, delay reset for 180s [1 => 0 at 19:41:19; F/F as of 19:41:19/19:44:19] <condpypr5ww>
      Z-F-group "kit pendant auto" (AND)  false as of 16:47:48 <grppypn9cs>
      |     &-F-service Kitchen Pendants (10082) urn:upnp-org:serviceId:SwitchPower1/Status = 1 [1 => 0 at 19:54:16; F/F as of 19:54:16/19:54:16] <condpypoe3z>
      |     &-F-service motion kitchen (10182) urn:micasaverde-com:serviceId:SecuritySensor1/Tripped = 1 after condpypoe3z; output follow, delay reset for 180s [1 => 0 at 19:41:19; F/F as of 19:41:19/16:47:48] <condpyptpu8>
      Z-F-group "kit cab auto" (AND)  false as of 16:47:48 <grppypo1gi>
      |     &-F-service kitchen Under (10041) urn:upnp-org:serviceId:SwitchPower1/Status = 1 [0 at 16:47:48; F/F as of 16:47:48/16:47:48] <condpypof5g>
      |     &-F-service motion kitchen (10182) urn:micasaverde-com:serviceId:SecuritySensor1/Tripped = 1 after condpypof5g; output follow, delay reset for 180s [1 => 0 at 19:41:19; F/F as of 19:41:19/16:47:48] <condpypui5c>
      Z-X-group "lounge 1 auto" (AND)  false as of n/a DISABLED <grppyrfotb>
      |     &-?-service Lounge 1 (10008) urn:upnp-org:serviceId:SwitchPower1/Status = 1 [nil at n/a; F/F as of n/a/n/a] <condpyrgox3>
      |     &-?-service motion rear pir (10186) urn:micasaverde-com:serviceId:SecuritySensor1/Tripped = 1 after condpyrgox3; output follow, delay reset for 180s [nil at n/a; F/F as of n/a/n/a] <condpyrgq1p>
      Z-F-group "lounge 2 on" (AND)  false as of 17:52:21 <grppyrz6h6>
      |     &-T-group "grpramakax" (OR)  TRUE as of 16:47:48 <grpramakax>
      |     |     |-T-grpstate (self) (-1) is night (grppys1fa3) istrue [true at 16:47:48; T/T as of 16:47:48/16:47:48] <condraipdos>
      |     |     |-T-service Lounge 2 (10031) urn:upnp-org:serviceId:SwitchPower1/Status istrue  [0 => 1 at 18:01:25; T/T as of 18:01:25/18:01:25] <condraiqvfa>
      |     &-F-service Test Switch (20021) urn:upnp-org:serviceId:SwitchPower1/Status istrue ; output follow, delay reset for 600s [0 at 18:41:48; F/F as of 18:41:48/18:41:48] <cond10gjkab7>
      Z-X-group "wall auto" (AND)  false as of n/a DISABLED <grppysg0nr>
      |     &-?-service Wall (10019) urn:upnp-org:serviceId:SwitchPower1/Status = 1 [nil at n/a; F/F as of n/a/n/a] <condpysg2zk>
      |     &-?-service motion rear pir (10186) urn:micasaverde-com:serviceId:SecuritySensor1/Tripped = 1 after condpysg2zk; output follow, delay reset for 180s [nil at n/a; F/F as of n/a/n/a] <condpysg463>
    Activity grppypo1gi.false
        Device kitchen Under (10041) action urn:upnp-org:serviceId:Dimming1/SetLoadLevelTarget( newLoadlevelTarget="0" )
        Run Lua:
             1: luup.variable_set("urn:upnp-org:serviceId:Dimming1", "LoadLevelLast", "50", 10041)
    Activity grppxw08hq.false
        Device Kitchen Main (10043) action urn:upnp-org:serviceId:Dimming1/SetLoadLevelTarget( newLoadlevelTarget="0" )
        Run Lua:
             1: luup.variable_set("urn:upnp-org:serviceId:Dimming1", "LoadLevelLast", "50", 10043)
    Activity grppyrfotb.true
        Device Lounge 1 (10008) action urn:upnp-org:serviceId:Dimming1/SetLoadLevelTarget( newLoadlevelTarget="{loadlevellounge1}" )
    Activity grppxw08hq.true
        Device Kitchen Main (10043) action urn:upnp-org:serviceId:Dimming1/SetLoadLevelTarget( newLoadlevelTarget="{loadlevelkit}" )
    Activity grppypn9cs.false
        Device Kitchen Pendants (10082) action urn:upnp-org:serviceId:Dimming1/SetLoadLevelTarget( newLoadlevelTarget="0" )
        Run Lua:
             1: luup.variable_set("urn:upnp-org:serviceId:Dimming1", "LoadLevelLast", "50", 10082)
    Activity grppyrfotb.false
        Device Lounge 1 (10008) action urn:upnp-org:serviceId:Dimming1/SetLoadLevelTarget( newLoadlevelTarget="0" )
        Run Lua:
             1: luup.variable_set("urn:upnp-org:serviceId:Dimming1", "LoadLevelLast", "20", 10008)
    Activity grppyrz6h6.false
        Device Lounge 2 (10031) action urn:upnp-org:serviceId:Dimming1/SetLoadLevelTarget( newLoadlevelTarget="0" )
        Run Lua:
             1: luup.variable_set("urn:upnp-org:serviceId:Dimming1", "LoadLevelLast", "20", 10031)
    Activity grppypqpw6.true
        Notify method SM nid 2: message "Luup reload"; recipient="sidstone909@gmail.com"; index="1"; subject="luup reload OpenLuup"; SMTPServer="smtp.gmail.com"; SMTPPort="465"; SMTPSender="thecid910@gmail.com"; SMTPDefaultRecipient="thecid910@gmail.com"; SMTPDefaultSubject="Reactor notification"; SMTPUsername="thecid910@gmail.com"; SMTPPassword="*"; SSL opt {"verify":"none","mode":"client","protocol":"any"}
    Activity grppyrz6h6.true
        Device Lounge 2 (10031) action urn:upnp-org:serviceId:Dimming1/SetLoadLevelTarget( newLoadlevelTarget="{loadlevellounge2}" )
    Activity grppysg0nr.false
        Device Wall (10019) action urn:upnp-org:serviceId:Dimming1/SetLoadLevelTarget( newLoadlevelTarget="0" )
        Run Lua:
             1: luup.variable_set("urn:upnp-org:serviceId:Dimming1", "LoadLevelLast", "30", 10019)
    Activity grppypo1gi.true
        Device kitchen Under (10041) action urn:upnp-org:serviceId:Dimming1/SetLoadLevelTarget( newLoadlevelTarget="{loadlevelcab}" )
    Activity grppysg0nr.true
        Device Wall (10019) action urn:upnp-org:serviceId:Dimming1/SetLoadLevelTarget( newLoadlevelTarget="{loadlevelwall}" )
    Activity grppypn9cs.true
        Device Kitchen Pendants (10082) action urn:upnp-org:serviceId:Dimming1/SetLoadLevelTarget( newLoadlevelTarget="{loadlevelpen}" )
    Events
        2020-12-22 20:04:08.182: Reactor startup (Luup reload)
        2020-12-22 20:04:08.346: Starting (Luup Startup/Reload)
        2020-12-22 20:04:09.407: Sensor update starting
        2020-12-22 20:04:09.440: Condition condpxw4kq6 test state changed from false to true
        2020-12-22 20:04:09.440: Condition condpxw4kq6 evaluation state changed from false to true
        2020-12-22 20:04:09.441: Group monitor luup reload test state changed from false to true
        2020-12-22 20:04:09.441: Group monitor luup reload evaluation state changed from false to true
        2020-12-22 20:04:09.483: Preparing monitor luup reload.true (grppypqpw6.true) activity
        2020-12-22 20:04:09.485: Launching scene/activity "grppypqpw6.true"
        2020-12-22 20:04:09.488: Deferring scene execution, system not ready (grppypqpw6.true:1:0)
        2020-12-22 20:04:09.491: Sensor update completed; 0.084s
        2020-12-22 20:04:09.700: Sensor update starting
        2020-12-22 20:04:09.705: Condition condpxw4kq6 test state changed from true to false
        2020-12-22 20:04:09.706: Condition condpxw4kq6 evaluation state changed from true to false
        2020-12-22 20:04:09.706: Group monitor luup reload test state changed from true to false
        2020-12-22 20:04:09.707: Group monitor luup reload evaluation state changed from true to false
        2020-12-22 20:04:09.720: Sensor update completed; 0.020s
        2020-12-22 20:04:14.757: Starting "grppypqpw6.true" group 1 at step 1
        2020-12-22 20:04:16.000: Activity "grppypqpw6.true" finished in 6.5150001049042s
        2020-12-22 20:04:16.001: Stopping activity "grppypqpw6.true"
    Devices
        kitchen Under (10041) urn:schemas-upnp-org:device:DimmableLight:1 (2/0); parent 1; plugin -; mfg  model ; dev D_DimmableLight1.xml impl X
        Kitchen Main (10043) urn:schemas-upnp-org:device:DimmableLight:1 (2/0); parent 1; plugin -; mfg  model ; dev D_DimmableLight1.xml impl X
        Test Switch (20021) urn:schemas-upnp-org:device:BinaryLight:1 (3/1); parent 24; plugin -; mfg  model ; dev D_BinaryLight1.xml impl X
        VeraBridge (5) VeraBridge (1/0); parent 0; plugin -; mfg akbooer model ; dev D_VeraBridge.xml impl I_VeraBridge.xml
        Zigbee Network (10002) urn:schemas-micasaverde-com:device:ZigbeeNetwork:1 (0/0); parent 5; plugin -; mfg Mi Casa Verde model GC100; dev D_ZigbeeNetwork.xml impl X
        motion kitchen (10182) urn:schemas-micasaverde-com:device:MotionSensor:1 (4/3); parent 5; plugin -; mfg  model ; dev D_MotionSensor1.xml impl X
        motion rear pir (10186) urn:schemas-micasaverde-com:device:MotionSensor:1 (4/3); parent 5; plugin -; mfg  model ; dev D_MotionSensor1.xml impl X
        Lounge 1 (10008) urn:schemas-upnp-org:device:DimmableLight:1 (2/0); parent 1; plugin -; mfg  model ; dev D_DimmableLight1.xml impl X
        Door sensor (10166) urn:schemas-micasaverde-com:device:DoorSensor:1 (4/1); parent 10002; plugin -; mfg  model ; dev D_DoorSensor1.xml impl X
        Lounge 2 (10031) urn:schemas-upnp-org:device:DimmableLight:1 (2/0); parent 1; plugin -; mfg  model ; dev D_DimmableLight1.xml impl X
        Wall (10019) urn:schemas-upnp-org:device:DimmableLight:1 (2/0); parent 1; plugin -; mfg  model ; dev D_DimmableLight1.xml impl X
        Ezlo Bridge (24) urn:schemas-rboer-com:device:EzloBridge:1 (1/0); parent 0; plugin -; mfg ReneBoer model ; dev D_EzloBridge.xml impl I_EzloBridge.xml
        ZWave (1) urn:schemas-micasaverde-com:device:ZWaveNetwork:1 (19/0); parent 5; plugin -; mfg Mi Casa Verde model GC100; dev D_ZWaveNetwork.xml impl X
        Kitchen Pendants (10082) urn:schemas-upnp-org:device:DimmableLight:1 (2/0); parent 1; plugin -; mfg  model ; dev D_DimmableLight1.xml impl X
    Watches
        Device #10182 motion kitchen service urn:micasaverde-com:serviceId:SecuritySensor1 variable Tripped
        Device #20021 Test Switch service urn:upnp-org:serviceId:SwitchPower1 variable Status
        Device #10019 Wall service urn:upnp-org:serviceId:Dimming1 variable LoadLevelLast
        Device #10043 Kitchen Main service urn:upnp-org:serviceId:Dimming1 variable LoadLevelLast
        Device #10041 kitchen Under service urn:upnp-org:serviceId:Dimming1 variable LoadLevelLast
        Device #10082 Kitchen Pendants service urn:upnp-org:serviceId:SwitchPower1 variable Status
        Device #14 Reactor Sensor 3 service urn:toggledbits-com:serviceId:ReactorSensor variable TestHouseMode
        Device #14 Reactor Sensor 3 service urn:toggledbits-com:serviceId:ReactorGroup variable GroupStatus_grppys1fa3
        Device #10041 kitchen Under service urn:upnp-org:serviceId:SwitchPower1 variable Status
        Device #10043 Kitchen Main service urn:upnp-org:serviceId:SwitchPower1 variable Status
        Device #10031 Lounge 2 service urn:upnp-org:serviceId:SwitchPower1 variable Status
        Device #10166 Door sensor service urn:upnp-org:serviceId:SwitchPower1 variable Status
        Device #10031 Lounge 2 service urn:upnp-org:serviceId:Dimming1 variable LoadLevelLast
        Device #10082 Kitchen Pendants service urn:upnp-org:serviceId:Dimming1 variable LoadLevelLast
        Device #14 Reactor Sensor 3 service urn:toggledbits-com:serviceId:ReactorSensor variable cdata
        Device #10008 Lounge 1 service urn:upnp-org:serviceId:Dimming1 variable LoadLevelLast
        Device #14 Reactor Sensor 3 service urn:toggledbits-com:serviceId:ReactorSensor variable TestTime
    Special Configuration
        Retrigger = 0

here is image of status and conditionn one is 1 and other 0

Screenshot_20201222-203450
Screenshot_20201222-2034501920Ɨ1080 160 KB

Screenshot_20201222-203522
Screenshot_20201222-2035221920Ɨ1080 164 KB

#6

That suggests to me an issue with the eZLO Bridge. When a subject device variable changes, you will see this kind of message in the events section:

2020-12-22 17:15:29.643: Device Kitchen Main (#10043) urn:upnp-org:serviceId:SwitchPower1/Status changed from "0" to "1"
#7

THe device is updating in th logs

luup.variable_set:: 20021.urn:upnp-org:serviceId:SwitchPower1.Status was: 1 now: 0 #hooks:0
2020-12-22 21:18:14.295   luup.variable_set:: 20021.urn:upnp-org:serviceId:SwitchPower1.Target was: 1 now: 0 #hooks:0
2020-12-22 21:18:14.505   openLuup.server:: request completed (10485 bytes, 1 chunks, 2622 ms) tcp{client}: 0xfdf7578
2020-12-22 21:18:14.929   openLuup.server:: GET /data_request?id=lu_status2&output_format=json&DataVersion=670241346&Timeout=60&MinimumDelay=1500&_=1608666824852 HTTP/1.1 tcp{client}: 0xfdf7578
2020-12-22 21:18:16.135   openLuup.server:: GET /data_request?id=action&output_format=json&DeviceNum=20021&serviceId=urn:upnp-org:serviceId:SwitchPower1&action=SetTarget&newTargetValue=1 HTTP/1.1 tcp{client}: 0xea762b08
2020-12-22 21:18:16.136   luup.call_action:: 20021.urn:upnp-org:serviceId:SwitchPower1.SetTarget 
2020-12-22 21:18:16.137   luup.call_action:: action will be handled by parent: 24
2020-12-22 21:18:16.138   openLuup.server:: request completed (62 bytes, 1 chunks, 2 ms) tcp{client}: 0xea762b08
2020-12-22 21:18:16.341   luup.variable_set:: 20021.urn:upnp-org:serviceId:SwitchPower1.Status was: 0 now: 1 #hooks:0
2020-12-22 21:18:16.342   luup.variable_set:: 20021.urn:upnp-org:serviceId:SwitchPower1.Target was: 0 now: 1 #hooks:0
2020-12-22 21:18:16.552   openLuup.server:: request completed (10485 bytes, 1 chunks, 1621 ms) tcp{client}: 0xfdf7578
2020-12-22 21:18:16.933   openLuup.server:: GET /data_request?id=lu_status2&output_format=json&DataVersion=670241349&Timeout=60&MinimumDelay=1500&_=1608666824853 HTTP/1.1 tcp{client}: 0xfdf7578
2020-12-22 21:18:18.265   openLuup.server:: GET /data_request?id=action&output_format=json&DeviceNum=20021&serviceId=urn:upnp-org:serviceId:SwitchPower1&action=SetTarget&newTargetValue=0 HTTP/1.1 tcp{client}: 0xea762b08
2020-12-22 21:18:18.266   luup.call_action:: 20021.urn:upnp-org:serviceId:SwitchPower1.SetTarget 
2020-12-22 21:18:18.267   luup.call_action:: action will be handled by parent: 24
2020-12-22 21:18:18.268   openLuup.server:: request completed (62 bytes, 1 chunks, 2 ms) tcp{client}: 0xea762b08
2020-12-22 21:18:18.483   openLuup.server:: request completed (9607 bytes, 1 chunks, 1199 ms) tcp{client}: 0xfdf7578
2020-12-22 21:18:18.484   luup.variable_set:: 20021.urn:upnp-org:serviceId:SwitchPower1.Status was: 1 now: 0 #hooks:0
2020-12-22 21:18:18.486   luup.variable_set:: 20021.urn:upnp-org:serviceId:SwitchPower1.Target was: 1 now: 0 #hooks:0
2020-12-22 21:18:18.953   openLuup.server:: GET /data_request?id=lu_status2&output_format=json&DataVersion=670241350&Timeout=60&MinimumDelay=1500&_=1608666824854 HTTP/1.1 tcp{client}: 0xfdf7578
2020-12-22 21:18:19.061   openLuup.server:: request completed (5340 bytes, 1 chunks, 106 ms) tcp{client}: 0xfdf7578
2020-12-22 21:18:19.405   openLuup.server:: GET /data_request?id=lu_status2&output_format=json&DataVersion=670241352&Timeout=60&MinimumDelay=1500&_=1608666824855 HTTP/1.1 tcp{client}: 0xfdf7578
2020-12-22 21:18:23.928   openLuup.server:: GET /openLuup?page=log HTTP/1.1 tcp{client}: 0xea762b08
#8

and i can turn device on in either UI and it will update in the other.
I think itā€™s an ezlo or ezlo bridge issue as the senser group works with any other switch including another switch on the ezlo hub. But test switch is an ezlo virtual switch.

#9

Well, then weā€™re going to have to engage @akbooerā€¦

We have a situation in which it appears a watch is not being placed on a device when requested, or callbacks are not being called. The device is high-numbered, 20021, the only one in that 20K range, and is a child of the eZLO Bridge plugin. All other devices are working correctly, and are lower-numbered and not associated with the eZLO Bridge.

This line from the Logic Summary indicates that Reactor has placed a watch on the variable (it keeps a table of things it has already watched to avoid dups):

    Watches
        ...
        Device #20021 Test Switch service urn:upnp-org:serviceId:SwitchPower1 variable Status

So Reactor thinks it is watching the variable. This is working for the other 18 or so watches placed on other devices (can be seen in posted logic summaries above). This device seems to be the only one for which it not working.

But as evidenced by all of @ElCidā€™s Reactor event logs, thereā€™s no watch callbacks being run for this device, and the LuaUPnP log data he sent shows ā€˜#hooks: 0ā€™ ā€“ that there are no watches in place???

2020-12-22 21:18:16.136   luup.call_action:: 20021.urn:upnp-org:serviceId:SwitchPower1.SetTarget 
2020-12-22 21:18:16.137   luup.call_action:: action will be handled by parent: 24
2020-12-22 21:18:16.138   openLuup.server:: request completed (62 bytes, 1 chunks, 2 ms) tcp{client}: 0xea762b08
2020-12-22 21:18:16.341   luup.variable_set:: 20021.urn:upnp-org:serviceId:SwitchPower1.Status was: 0 now: 1 #hooks:0
2020-12-22 21:18:16.342   luup.variable_set:: 20021.urn:upnp-org:serviceId:SwitchPower1.Target was: 0 now: 1 #hooks:0

@akbooer, my code in Reactor that sets watches treats no device differently from any other, so Iā€™m at a loss as to why it works for 18 other devices but not this one.

One other thing to note: it is also the only device of type BinaryLight (urn:schemas-upnp-org:device:BinaryLight:1)ā€¦ looks like @ElCid is running 200522ā€¦ could it be these services werenā€™t declared in that versionā€™s VFS? I donā€™t recall when you added all of thoseā€¦

#10

Just to add if i set the switch to device 20009, another ezlo switch type dimming. Then all works as status updates. If i add a virtual dimmer this works on loadlevelstatus, but no status as it does not update. device 20021 status updates but does not trip.

I have it working again with test dimmer device 20023.
The strange thing is it was working last night when i set it up using test switch 20021.
I will wait to see what @akbooer says.

#11

@ElCid what else have you changed there recently? Iā€™m seeing all the generic ZWave icons on a lot of your devices, including not just the ReactorSensors, but switches and dimmers as wellā€¦ maybe youā€™re having a bigger issue with servicesā€¦

#12

Only update ALTUI, Reactor and Openluup and Ezlo bridge via altui plugin page, and set up this test switch

#13

It looks like you actually downgraded your openLuupā€¦ the first Logic Summary you sent me reported running openLuup 200629, and the last one you posted was 200522. I hate to have you change anything until akbooer chimes in, because that would make a moving target for him, but I suspect the downgrade is somehow complicit here, and maybe more yet to come.

#14

Engaged, but not yet understanding the problemā€¦

  • using the Ezlo bridge by @reneboer
  • not seeing Reactor by @rigpapa responding to triggers
  • @ElCid showing missing icons.

ā€¦where shall we start looking?

Iā€™d suggest looking carefully at

  • the startup log and the initial section of the main log
  • the openLuup console Scheduler > Startup and Plugins pages
  • console openLuup > HTTP page

ā€¦for any errors.

Also, the Scheduler > watches page, to see what variables are being watched.

Iā€™d recommend an update to the latest openLuup development version, but assume thatā€™s not, in fact, the issue.

Itā€™s perfectly possible to set a device variable without causing a watch to trigger, but you have to do that in an explicit way, which I presume the bridge plugin doesnā€™t choose to do.

#15

Confirmed the bridge does not appear to be doing this.

This is how Reactor sets watches:

local function addServiceWatch( dev, svc, var, target )
	-- Don't watch our own variables--we update them in sequence anyway
	if dev == target and svc == VARSID then return end
	target = tostring(target)
	local watchkey = string.format("%d/%s/%s", dev or 0, svc or "X", var or "X")
	if watchData[watchkey] == nil then
		D("addServiceWatch() adding system watch for %1", watchkey)
		luup.variable_watch( "reactorWatch", svc or "X", var or "X", dev or 0 )
		watchData[watchkey] = watchData[watchkey] or {}
	end
	if watchData[watchkey][target] == nil then
		D("addServiceWatch() subscribing %1 to %2", target, watchkey)
		watchData[watchkey][target] = true
	-- else D("addServiceWatch() %1 is already subscribed to %2", target, watchkey)
	end
end

This has been working since version 1.0, and has worked for everything up until this eZLO Bridge device. The fact that the event section of the logic summary emits the message I referenced above means that the entry is in watchData. The purpose of watchData is to allow multiple children (ReactorSensors) to watch the same device (so one callback services all children).

But I donā€™t think itā€™s the eZLO Bridge, I think it has something to do with the service.

@akbooer, if you agree, Iā€™d like to have @ElCid do the following:

  1. Upgrade to current ā€œdevelopmentā€ branch (please give instructions for @ElCid to do this ā€“ I use command-line Github for this and I donā€™t think thatā€™s going to help him).
  2. Retest. If weā€™re still not goodā€¦
  3. Turn on DebugMode in the master ReactorSensor, and reload openLuup.
  4. Immediately grab the LuaUPnP.log file and send it to me via the email address in the Tools tab of the ReactorSensor. I will confirm that the watch call is being made.
  5. If the watch call is being made, Retest with the switch.
  6. If the switch is still not functioning (would be expected at this point if it failed at step 2), then send LuaUPnP log to me again. Iā€™ll review. If I donā€™t see any Reactor issues, Iā€™ll send both logs to @akbooer.

Please advise.

#16

Yup, thatā€™s fine.

Simply update openLuup by going to the Plugins page, typing development into the Update box and pressing the update button. It could take up to a minute, before it restarts. Refresh the browser page.

#17

Cool. @ElCid, place make sure you ZIP the log file and sent it as an attachment on the email; please donā€™t PDF it or do any other translations. As raw as it gets plus compression is the way we like it.

#18

@rigpapa log sent.

@akbooer logs look fine. Start up and plugins look good and http looks good.

There is no watch for 20021, when i change to device 20009 zwave dimmer there is a watch and on 200023 test dimmer.

edit/ After some time device 20023 vitual dimmer stops registering a variable watch in scheduler. seems these ezlo virtual devices do not like playing fair. The ezlo zwave dimmer 20009 works fine

#19

Unfortunately it appears the log rotated after the reload, so thereā€™s not enough log here to work with; it doesnā€™t show the reload/startup. I need you to do it again, and hopefully weā€™ll catch the startup before rotation.

#20

OK. It looks like you changed the condition to use dimmer 20023, but here is where Reactor is putting in the watch, which openLuup appears to confirm:

2020-12-23 02:23:22.802   luup_log:10: Reactor(processCondition:4141): processCondition("cond10gjkab7","grppyrz6h6",cdata,14)
2020-12-23 02:23:22.803   luup_log:10: Reactor(evaluateCondition:3564): evaluateCondition("cond10gjkab7","grppyrz6h6",cdata,14)
2020-12-23 02:23:22.806   luup_log:10: Reactor(evaluateCondition:3571): evaluateCondition() condstate { statestamp=1608683849(2020-12-23.00:37:29), stateedge={ t=1608683849(2020-12-23.00:37:29), f=1608683826(2020-12-23.00:37:06) }, id="cond10gjkab7", evalstamp=1608683218(2020-12-23.00:26:58), lastvalue="32", evalstate=true, priorvalue="1", valuestamp=1608685501(2020-12-23.01:05:01), matchcount=5, laststate=true, evaledge={ t=1608683218(2020-12-23.00:26:58), f=1608683166(2020-12-23.00:26:06) } }

2020-12-23 02:23:22.806   luup_log:10: Reactor(addServiceWatch:621): addServiceWatch() adding system watch for "20023/urn:upnp-org:serviceId:Dimming1/LoadLevelStatus"
2020-12-23 02:23:22.808   luup.variable_watch:: callback=reactorWatch, watching=20023.urn:upnp-org:serviceId:Dimming1.LoadLevelStatus

2020-12-23 02:23:22.808   luup_log:10: Reactor(addServiceWatch:626): addServiceWatch() subscribing "14" to "20023/urn:upnp-org:serviceId:Dimming1/LoadLevelStatus"

I think you said that this device also does not trip. So go ahead and test with it, and send the logs after that test. If Iā€™m wrong about that and the dimmer works but the binary switch does not, then we need to start all over (change the condition back to the device that doesnā€™t work).

EDIT: Since itā€™s clear with the time differences that the test isnā€™t going to happen soon/in close proximity to the previous logs, please restart the test from the beginning anyway, so we can get both the startup log and a subsequent test within a short period. Make no other changes, except if you need to change the device back to the switch. Also send along a new logic summary, so I have a view of what the log is going to be showing.