We have moved at community.getvera.com

Author Topic: Inexplicable Execution  (Read 451 times)

Offline Z-Waver

  • Master Member
  • *******
  • Posts: 4437
  • Karma: +249/-120
Inexplicable Execution
« on: September 30, 2016, 10:21:24 am »
I need fresh eyes. This is not a "problem" but it annoys me that I can't see why this is happening.

I have a UI5 Vera with a standard scheduled scene(Sunrise + 5 minutes) that turns Off a bunch of lights. For one light in the bunch, this schedule is a little too early and I frequently manually turn the dimmer(WD500Z-1) back On just a few seconds after it goes Off.

The problem is that a few seconds after I manually turn it On, the dimmer turns Off again and I'm unable to see where the second Off command is coming from. (See log snippet below.) A second manual turn On ends the "fight". If I wait for many seconds(~1 minute) before manually turning On, I do not get the second turn Off.

I've verified that there are no other scenes, triggers, PLEGs, Veras, or other controllers acting on this dimmer. It seems as if the scene is still active and is running through the list of devices a second time. I didn't think scenes worked this way.

Code: [Select]
# grep -e 'node 51' -e 'device: 84' -e 'Kitchen Lights"' /var/log/cmh/LuaUPnP.log
02        09/30/16 7:24:39.102        ZW_Send_Data node 51 USING ROUTE 255.32.60.47 <0x2be43680>
04        09/30/16 7:24:39.227        <Job ID="102" Name="pollnode #51 1 cmds" Device="84" Created="2016-09-30 7:24:39" Started="2016-09-30 7:24:39" Completed="2016-09-30 7:24:39" Duration="0.125674000" Runtime="0.124822000" Status="Successful" LastNote="" Node="51" NodeType="ZWaveDimmableLight" NodeDescription="Kitchen Lights"/> <0x2ba43680>
08        09/30/16 7:26:45.109        JobHandler_LuaUPnP::HandleActionRequest device: 84 service: urn:upnp-org:serviceId:Dimming1 action: SetLoadLevelTarget <0x2ba43680>
06        09/30/16 7:26:45.109        Device_Variable::m_szValue_set device: 84 service: urn:upnp-org:serviceId:Dimming1 variable: LoadLevelTarget was: 0 now: 0 #hooks: 0 upnp: 0 v:0xfe6e40/NONE duplicate:1 <0x2ba43680>
02        09/30/16 7:26:45.308        ZW_Send_Data node 51 USING ROUTE 255.32.60.47 <0x2be43680>
02        09/30/16 7:27:01.010        ZW_Send_Data node 51 USING ROUTE 255.32.60.47 <0x2be43680>
06        09/30/16 7:27:01.116        Device_Variable::m_szValue_set device: 84 service: urn:upnp-org:serviceId:Dimming1 variable: LoadLevelStatus was: 100 now: 0 #hooks: 3 upnp: 0 v:0xfe6418/NONE duplicate:0 <0x2ba43680>
06        09/30/16 7:27:01.117        Device_Variable::m_szValue_set device: 84 service: urn:upnp-org:serviceId:SwitchPower1 variable: Status was: 1 now: 0 #hooks: 0 upnp: 0 v:0xf984d8/NONE duplicate:0 <0x2ba43680>
04        09/30/16 7:27:01.118        <Job ID="109" Name="Level 0 node 51" Device="84" Created="2016-09-30 7:26:45" Started="2016-09-30 7:26:45" Completed="2016-09-30 7:27:01" Duration="16.8179000" Runtime="15.810869000" Status="Successful" LastNote="Transmit was ok" Node="51" NodeType="ZWaveDimmableLight" NodeDescription="Kitchen Lights"/> <0x2ba43680>
02        09/30/16 7:34:29.102        ZW_Send_Data node 51 USING ROUTE 255.32.60.47 <0x2be43680>
06        09/30/16 7:34:29.226        Device_Variable::m_szValue_set device: 84 service: urn:upnp-org:serviceId:SwitchPower1 variable: Status was: 0 now: 1 #hooks: 0 upnp: 0 v:0xf984d8/NONE duplicate:0 <0x2ba43680>
06        09/30/16 7:34:29.226        Device_Variable::m_szValue_set device: 84 service: urn:upnp-org:serviceId:Dimming1 variable: LoadLevelStatus was: 0 now: 100 #hooks: 3 upnp: 0 v:0xfe6418/NONE duplicate:0 <0x2ba43680>
04        09/30/16 7:34:29.228        <Job ID="136" Name="pollnode #51 1 cmds" Device="84" Created="2016-09-30 7:34:29" Started="2016-09-30 7:34:29" Completed="2016-09-30 7:34:29" Duration="0.127023000" Runtime="0.126123000" Status="Successful" LastNote="" Node="51" NodeType="ZWaveDimmableLight" NodeDescription="Kitchen Lights"/> <0x2ba43680>