Hi,
I’ve got a PIR that switches on the kitchen light on movement, and then should switch off if not activity for 10 minutes. It has worked fine for a while but seems to be acting up lately, sometimes switching off while we are in front of the PIR. I’ve extracted a portion of my Vera log when this happened, if anyone can have a look and see if they can see a problem? Thanks in advance.
01 04/06/14 20:16:13.131 e[31;1mZWaveNode::CurrentRouteFailed node 15 device 102 position 31 route 8.2.4.0 hop 1 (from 6)e[0m <0x2b749680>
06 04/06/14 20:16:13.132 Device_Variable::m_szValue_set device: 102 service: urn:micasaverde-com:serviceId:ZWaveDevice1 variable: e[35;1mAutoRoutee[0m was: 2.4-48x,13.2.4-58x,11.2.4-64x,8.2.4-65 now: 2.4-48x,13.2.4-58x,11.2.4-64x,8.2.4-65x #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:0 <0x2b749680>
06 04/06/14 20:16:13.132 Device_Variable::m_szValue_set device: 1 service: urn:micasaverde-com:serviceId:ZWaveNetwork1 variable: e[35;1mLastRouteFailuree[0m was: 1396808159 now: 1396808173 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:0 <0x2b749680>
02 04/06/14 20:16:13.133 e[33;1mCurrentRouteFailed XXX1 (null)e[0m <0x2b749680>
02 04/06/14 20:16:13.133 e[33;1mCurrentRouteFailed XXX3 2.4-48x,13.2.4-58x,11.2.4-64x,8.2.4-65xe[0m <0x2b749680>
02 04/06/14 20:16:13.133 e[33;1mCurrentRouteFailed XXX4e[0m <0x2b749680>
02 04/06/14 20:16:13.134 e[33;1mUpdateManualRoute XXX1 node 15 route 2.4-48x,13.2.4-58x,11.2.4-64x,8.2.4-65xe[0m <0x2b749680>
06 04/06/14 20:16:13.134 Device_Variable::m_szValue_set device: 102 service: urn:micasaverde-com:serviceId:ZWaveDevice1 variable: e[35;1mAllRoutesFailede[0m was: 0 now: 1 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:0 <0x2b749680>
02 04/06/14 20:16:13.135 e[33;1mXXXX CurrentRouteFailed node 15 m_cRoutePosition 0 route 0.2.4.0e[0m <0x2b749680>
02 04/06/14 20:16:13.135 e[33;1mZWJob_SendData::ReceivedFrame job job#2518 :Lock node 15 dev:102 (0xdedfb0) N:15 P:70 S:5 to node 15 command 98/1 failed m_cTxStatus 6 retries 2e[0m <0x2b749680>
02 04/06/14 20:16:13.137 e[33;1mUPDATE MANUAL ROUTE2 15=(nil)e[0m <0x2bb49680>
02 04/06/14 20:16:13.137 e[33;1mZW_Send_Data node 15 NO ROUTE (nil)e[0m <0x2bb49680>
02 04/06/14 20:16:13.138 e[33;1mZW_Send_Data node 15 NO ROUTE (nil)e[0m <0x2bb49680>
06 04/06/14 20:16:14.311 Device_Variable::m_szValue_set device: 102 service: urn:micasaverde-com:serviceId:HaDevice1 variable: e[35;1mCommFailuree[0m was: 1 now: 0 #hooks: 0 upnp: 0 v:0x827568/NONE duplicate:0 <0x2b749680>
06 04/06/14 20:16:14.312 Device_Variable::m_szValue_set device: 1 service: urn:micasaverde-com:serviceId:ZWaveNetwork1 variable: e[35;1mLastErrore[0m was: Node 15 failed now: Node 15 failed #hooks: 0 upnp: 0 v:0x951ca0/NONE duplicate:1 <0x2b749680>
02 04/06/14 20:16:14.312 e[33;1mZWJob_SendData::ReceivedFrame ok job job#2518 :Lock node 15 dev:102 (0xdedfb0) N:15 P:70 S:5 to node 15 command 98/1 took 3 retries resend: 0 waiting 0/0 got 0e[0m <0x2b749680>
04 04/06/14 20:16:14.314 <Job ID="2518" Name="Lock node 15" Device="102" Created="2014-04-06 20:15:57" Started="2014-04-06 20:15:57" Completed="2014-04-06 20:16:14" Duration="17.109289000" Runtime="17.105267000" Status="Successful" LastNote="Transmit was ok" Node="15" NodeType="ZWaveDoorlock" NodeDescription="Front Door"/> <0x2b749680>
02 04/06/14 20:16:14.592 e[33;1mZW_Send_Data node 15 NO ROUTE (nil)e[0m <0x2b749680>
01 04/06/14 20:16:15.870 e[31;1mluvd_get_info /etc/cmh-ludl/S_Weather.xml.lzo doesn't existe[0m <0x2f149680>
02 04/06/14 20:16:16.562 e[33;1mZWJob_SendData UPDATE MANUAL ROUTE 15=(nil)e[0m <0x2b749680>
02 04/06/14 20:16:16.563 e[33;1mUPDATE MANUAL ROUTE2 15=(nil)e[0m <0x2bb49680>
02 04/06/14 20:16:16.564 e[33;1mZW_Send_Data node 15 NO ROUTE (nil)e[0m <0x2bb49680>
04 04/06/14 20:16:16.913 <Job ID="2520" Name="time_rep" Device="102" Created="2014-04-06 20:16:16" Started="2014-04-06 20:16:16" Completed="2014-04-06 20:16:16" Duration="0.350185000" Runtime="0.349074000" Status="Successful" LastNote="Transmit was ok" Node="15" NodeType="ZWaveDoorlock" NodeDescription="Front Door"/> <0x2b749680>
01 04/06/14 20:16:17.032 e[31;1mluvd_get_info /etc/cmh-ludl/S_ProgramLogicEG.xml.lzo doesn't existe[0m <0x2f149680>
01 04/06/14 20:16:17.035 e[31;1mluvd_get_info /etc/cmh-ludl/S_ProgramLogicC.xml.lzo doesn't existe[0m <0x2f149680>
02 04/06/14 20:16:17.132 e[33;1mZWJob_SendData UPDATE MANUAL ROUTE 15=(nil)e[0m <0x2b749680>
02 04/06/14 20:16:17.133 e[33;1mUPDATE MANUAL ROUTE2 15=(nil)e[0m <0x2bb49680>
02 04/06/14 20:16:17.134 e[33;1mZW_Send_Data node 15 NO ROUTE (nil)e[0m <0x2bb49680>
04 04/06/14 20:16:17.493 <Job ID="2521" Name="date_rep" Device="102" Created="2014-04-06 20:16:17" Started="2014-04-06 20:16:17" Completed="2014-04-06 20:16:17" Duration="0.360547000" Runtime="0.359443000" Status="Successful" LastNote="Transmit was ok" Node="15" NodeType="ZWaveDoorlock" NodeDescription="Front Door"/> <0x2b749680>
06 04/06/14 20:16:24.166 Device_Variable::m_szValue_set device: 104 service: urn:upnp-org:serviceId:AVTransport variable: e[35;1mRelativeTimePositione[0m was: 00:03:20 now: 00:03:35 #hooks: 0 upnp: 0 v:0x94c150/NONE duplicate:0 <0x2db49680>
06 04/06/14 20:16:24.235 Device_Variable::m_szValue_set device: 104 service: urn:micasaverde-com:serviceId:HaDevice1 variable: e[35;1mLastUpdatee[0m was: 1396808169 now: 1396808184 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:0 <0x2db49680>
02 04/06/14 20:16:24.494 e[33;1mJobHandler::Run job#2519 :pollnode_callb #15 dev:102 (0xd71038) N:15 P:20 S:0 is 10.181315000 seconds olde[0m <0x2bb49680>
02 04/06/14 20:16:24.496 e[33;1mZW_Send_Data node 15 NO ROUTE (nil)e[0m <0x2bb49680>
02 04/06/14 20:16:24.497 e[33;1mZW_Send_Data node 15 NO ROUTE (nil)e[0m <0x2bb49680>
02 04/06/14 20:16:25.492 e[33;1mZW_Send_Data node 15 NO ROUTE (nil)e[0m <0x2b749680>
06 04/06/14 20:16:25.945 Device_Variable::m_szValue_set device: 102 service: urn:micasaverde-com:serviceId:DoorLock1 variable: e[35;1mStatuse[0m was: 0 now: 1 #hooks: 0 upnp: 0 v:0x921348/NONE duplicate:0 <0x2b749680>
02 04/06/14 20:16:25.982 e[33;1mZWJob_SendData UPDATE MANUAL ROUTE 15=(nil)e[0m <0x2b749680>
02 04/06/14 20:16:27.984 e[33;1mZW_Send_Data node 15 NO ROUTE (nil)e[0m <0x2bb49680>
06 04/06/14 20:16:28.542 Device_Variable::m_szValue_set device: 102 service: urn:micasaverde-com:serviceId:HaDevice1 variable: e[35;1mBatteryDatee[0m was: 1396684435 now: 1396808188 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:0 <0x2b749680>
06 04/06/14 20:16:28.542 Device_Variable::m_szValue_set device: 102 service: urn:micasaverde-com:serviceId:HaDevice1 variable: e[35;1mBatteryLevele[0m was: 96 now: 100 #hooks: 0 upnp: 0 v:0x827190/NONE duplicate:0 <0x2b749680>
04 04/06/14 20:16:28.544 <Job ID="2519" Name="pollnode_callb #15 2 cmds" Device="102" Created="2014-04-06 20:16:14" Started="2014-04-06 20:16:24" Completed="2014-04-06 20:16:28" Duration="14.230371000" Runtime="4.49128000" Status="Successful" LastNote="Successfully polled node" Node="15" NodeType="ZWaveDoorlock" NodeDescription="Front Door"/> <0x2b749680>
02 04/06/14 20:16:28.545 e[33;1mUPDATE MANUAL ROUTE2 15=(nil)e[0m <0x2bb49680>
02 04/06/14 20:16:28.546 e[33;1mZW_Send_Data node 15 NO ROUTE (nil)e[0m <0x2bb49680>
04 04/06/14 20:16:28.903 <Job ID="2522" Name="time_rep" Device="102" Created="2014-04-06 20:16:25" Started="2014-04-06 20:16:28" Completed="2014-04-06 20:16:28" Duration="2.920218000" Runtime="0.357142000" Status="Successful" LastNote="Transmit was ok" Node="15" NodeType="ZWaveDoorlock" NodeDescription="Front Door"/> <0x2b749680>
02 04/06/14 20:16:29.112 e[33;1mZWJob_SendData UPDATE MANUAL ROUTE 15=(nil)e[0m <0x2b749680>
02 04/06/14 20:16:29.113 e[33;1mUPDATE MANUAL ROUTE2 15=(nil)e[0m <0x2bb49680>
02 04/06/14 20:16:29.114 e[33;1mZW_Send_Data node 15 NO ROUTE (nil)e[0m <0x2bb49680>
04 04/06/14 20:16:29.463 <Job ID="2523" Name="date_rep" Device="102" Created="2014-04-06 20:16:29" Started="2014-04-06 20:16:29" Completed="2014-04-06 20:16:29" Duration="0.350371000" Runtime="0.349209000" Status="Successful" LastNote="Transmit was ok" Node="15" NodeType="ZWaveDoorlock" NodeDescription="Front Door"/> <0x2b749680>
50 04/06/14 20:16:35.012 luup_log:42: Received: unknowncommand 14 <0x2f949680>
01 04/06/14 20:16:37.782 e[31;1mluvd_get_info /etc/cmh-ludl/S_Weather.xml.lzo doesn't existe[0m <0x2f149680>
01 04/06/14 20:16:38.977 e[31;1mluvd_get_info /etc/cmh-ludl/S_ProgramLogicEG.xml.lzo doesn't existe[0m <0x2f149680>
01 04/06/14 20:16:38.979 e[31;1mluvd_get_info /etc/cmh-ludl/S_ProgramLogicC.xml.lzo doesn't existe[0m <0x2f149680>
06 04/06/14 20:16:39.154 Device_Variable::m_szValue_set device: 104 service: urn:upnp-org:serviceId:AVTransport variable: e[35;1mRelativeTimePositione[0m was: 00:03:35 now: 00:03:50 #hooks: 0 upnp: 0 v:0x94c150/NONE duplicate:0 <0x2db49680>
06 04/06/14 20:16:39.196 Device_Variable::m_szValue_set device: 104 service: urn:micasaverde-com:serviceId:HaDevice1 variable: e[35;1mLastUpdatee[0m was: 1396808184 now: 1396808199 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:0 <0x2db49680>
02 04/06/14 20:16:44.114 e[33;1mZW_Send_Data node 2 NO ROUTE (nil)e[0m <0x2bb49680>
02 04/06/14 20:16:46.253 e[33;1mZW_Send_Data node 2 NO ROUTE (nil)e[0m <0x2bb49680>
06 04/06/14 20:16:46.382 Device_Variable::m_szValue_set device: 6 service: urn:micasaverde-com:serviceId:EnergyMetering1 variable: e[35;1mWattse[0m was: 98 now: 99 #hooks: 0 upnp: 0 v:0x84a118/NONE duplicate:0 <0x2b749680>
06 04/06/14 20:16:46.383 Device_Variable::m_szValue_set device: 6 service: urn:micasaverde-com:serviceId:EnergyMetering1 variable: e[35;1mLoge[0m was: 98,97,99,1396807916,2517 now: 99,97,99,1396808206,2807 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:0 <0x2b749680>
06 04/06/14 20:16:46.383 Device_Variable::m_szValue_set device: 6 service: urn:micasaverde-com:serviceId:EnergyMetering1 variable: e[35;1mActualUsagee[0m was: 1 now: 1 #hooks: 0 upnp: 0 v:0x84ae98/NONE duplicate:1 <0x2b749680>
02 04/06/14 20:16:48.393 e[33;1mZW_Send_Data node 2 NO ROUTE (nil)e[0m <0x2bb49680>
06 04/06/14 20:16:48.532 Device_Variable::m_szValue_set device: 6 service: urn:micasaverde-com:serviceId:EnergyMetering1 variable: e[35;1mKWHe[0m was: 25.6830 now: 25.6910 #hooks: 0 upnp: 0 v:0x84a828/NONE duplicate:0 <0x2b749680>
06 04/06/14 20:16:48.533 Device_Variable::m_szValue_set device: 6 service: urn:micasaverde-com:serviceId:EnergyMetering1 variable: e[35;1mKWHReadinge[0m was: 1396807918 now: 1396808208 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:0 <0x2b749680>
02 04/06/14 20:16:50.542 e[33;1mZW_Send_Data node 2 NO ROUTE (nil)e[0m <0x2bb49680>
06 04/06/14 20:16:50.682 Device_Variable::m_szValue_set device: 6 service: urn:micasaverde-com:serviceId:EnergyMetering1 variable: e[35;1mWattse[0m was: 99 now: 97 #hooks: 0 upnp: 0 v:0x84a118/NONE duplicate:0 <0x2b749680>
06 04/06/14 20:16:50.683 Device_Variable::m_szValue_set device: 6 service: urn:micasaverde-com:serviceId:EnergyMetering1 variable: e[35;1mLoge[0m was: 99,97,99,1396808206,2807 now: 97,97,99,1396808210,2811 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:0 <0x2b749680>
06 04/06/14 20:16:50.683 Device_Variable::m_szValue_set device: 6 service: urn:micasaverde-com:serviceId:EnergyMetering1 variable: e[35;1mActualUsagee[0m was: 1 now: 1 #hooks: 0 upnp: 0 v:0x84ae98/NONE duplicate:1 <0x2b749680>
04 04/06/14 20:16:50.685 <Job ID="2524" Name="pollnode #2 4 cmds" Device="6" Created="2014-04-06 20:16:44" Started="2014-04-06 20:16:44" Completed="2014-04-06 20:16:50" Duration="6.571698000" Runtime="6.570665000" Status="Successful" LastNote="" Node="2" NodeType="ZWaveDimmableLight" NodeDescription="Lounge Lights"/> <0x2b749680>
I don’t even see a switch state change in that log. It’s pretty useless to me.
How about giving us some information up front? Is the PIR running a scene or controlling the light directly via association.
Ok, more detail. The PIR runs a scene when it is tripped to switch light on, and another scene to switch the lights off. It is not directly linked. It ‘should’ get tripped, wait for no movement for 2 minutes, then delay by 10 minutes and then switch off. So, in theory, if it is tripped, the lights should switch off after 12 minutes at the soonest.
It is an ACT ZIR010 PIR, and the light dimmer is an Aeon Labs Micro Smart Dimmer.
Here is another log of when it happened a few minutes ago. I have from the tripped signal, to when the lights went off, about 1m30s.
06 04/09/14 19:59:30.537 Device_Variable::m_szValue_set device: 4 service: urn:micasaverde-com:serviceId:SecuritySensor1 variable: e[35;1mTrippede[0m was: 0 now: 1 #hooks: 2 upnp: 0 v:0xd6e2c8/NONE duplicate:0 <0x2bc55680>
07 04/09/14 19:59:30.538 Event::Evaluate 1 Kitchen PIR triggered scene Switch on kitchen lights is true users:(null) allow:1 <0x2bc55680>
08 04/09/14 19:59:30.538 Scene::RunScene running 1 Switch on kitchen lights <0x2bc55680>
08 04/09/14 19:59:30.538 JobHandler_LuaUPnP::HandleActionRequest device: 97 service: urn:upnp-org:serviceId:Dimming1 action: e[36;1mSetLoadLevelTargete[0m <0x2bc55680>
08 04/09/14 19:59:30.539 JobHandler_LuaUPnP::HandleActionRequest argument newLoadlevelTarget=100 <0x2bc55680>
06 04/09/14 19:59:30.539 Device_Variable::m_szValue_set device: 97 service: urn:upnp-org:serviceId:Dimming1 variable: e[35;1mLoadLevelTargete[0m was: 0 now: 100 #hooks: 0 upnp: 0 v:0xd954f8/NONE duplicate:0 <0x2bc55680>
02 04/09/14 19:59:30.540 e[33;1mZWJob_SendData UPDATE MANUAL ROUTE 4=(nil)e[0m <0x2bc55680>
07 04/09/14 19:59:30.541 Event::Evaluate 2 Kitchen PIR off scene Switch off kitchen lights is false repeat 0/-1 <0x2bc55680>
06 04/09/14 19:59:30.541 Device_Variable::m_szValue_set device: 4 service: urn:micasaverde-com:serviceId:SecuritySensor1 variable: e[35;1mArmedTrippede[0m was: 0 now: 1 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:0 <0x2bc55680>
06 04/09/14 19:59:30.542 Device_Variable::m_szValue_set device: 4 service: urn:micasaverde-com:serviceId:SecuritySensor1 variable: e[35;1mLastTripe[0m was: 1397065918 now: 1397066370 #hooks: 0 upnp: 0 v:0xd73558/NONE duplicate:0 <0x2bc55680>
04 04/09/14 19:59:30.544 <Job ID="121" Name="pollnode #14 4 cmds" Device="100" Created="2014-04-09 19:59:27" Started="2014-04-09 19:59:27" Completed="2014-04-09 19:59:30" Duration="3.442176000" Runtime="3.440714000" Status="Aborted" LastNote="" Node="14" NodeType="ZWaveDimmableLight" NodeDescription="Kitchen Main"/> <0x2bc55680>
02 04/09/14 19:59:30.545 e[33;1mUPDATE MANUAL ROUTE2 4=(nil)e[0m <0x2be55680>
02 04/09/14 19:59:30.545 e[33;1mZW_Send_Data node 4 NO ROUTE (nil)e[0m <0x2be55680>
02 04/09/14 19:59:30.620 e[33;1mUPDATE MANUAL ROUTE2 4=(nil)e[0m <0x2be55680>
02 04/09/14 19:59:30.620 e[33;1mZW_Send_Data node 4 NO ROUTE (nil)e[0m <0x2be55680>
06 04/09/14 19:59:31.547 Device_Variable::m_szValue_set device: 97 service: urn:upnp-org:serviceId:Dimming1 variable: e[35;1mLoadLevelStatuse[0m was: 0 now: 100 #hooks: 5 upnp: 0 v:0xd8cb60/NONE duplicate:0 <0x2bc55680>
06 04/09/14 19:59:31.548 Device_Variable::m_szValue_set device: 97 service: urn:upnp-org:serviceId:SwitchPower1 variable: e[35;1mStatuse[0m was: 0 now: 1 #hooks: 0 upnp: 0 v:0xd89248/NONE duplicate:0 <0x2bc55680>
04 04/09/14 19:59:31.549 <Job ID="122" Name="Level 99 node 4" Device="97" Created="2014-04-09 19:59:30" Started="2014-04-09 19:59:30" Completed="2014-04-09 19:59:31" Duration="1.9172000" Runtime="1.4515000" Status="Successful" LastNote="Transmit was ok" Node="4" NodeType="ZWaveDimmableLight" NodeDescription="Kitchen Light"/> <0x2bc55680>
02 04/09/14 19:59:57.103 e[33;1mZW_Send_Data node 2 NO ROUTE (nil)e[0m <0x2be55680>
01 04/09/14 19:59:57.952 e[31;1mluvd_get_info /etc/cmh-ludl/S_Weather.xml.lzo doesn't existe[0m <0x2f855680>
01 04/09/14 19:59:58.092 e[31;1mluvd_get_info /etc/cmh-ludl/S_ProgramLogicEG.xml.lzo doesn't existe[0m <0x2f855680>
02 04/09/14 19:59:59.228 e[33;1mZW_Send_Data node 2 NO ROUTE (nil)e[0m <0x2be55680>
01 04/09/14 19:59:59.239 e[31;1mluvd_get_info /etc/cmh-ludl/S_ProgramLogicC.xml.lzo doesn't existe[0m <0x2f855680>
06 04/09/14 19:59:59.367 Device_Variable::m_szValue_set device: 6 service: urn:micasaverde-com:serviceId:EnergyMetering1 variable: e[35;1mWattse[0m was: 98 now: 97 #hooks: 0 upnp: 0 v:0xda5190/NONE duplicate:0 <0x2bc55680>
06 04/09/14 19:59:59.368 Device_Variable::m_szValue_set device: 6 service: urn:micasaverde-com:serviceId:EnergyMetering1 variable: e[35;1mLoge[0m was: 98,97,99,1397066159,1560 now: 97,97,99,1397066399,1800 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:0 <0x2bc55680>
06 04/09/14 19:59:59.369 Device_Variable::m_szValue_set device: 6 service: urn:micasaverde-com:serviceId:EnergyMetering1 variable: e[35;1mActualUsagee[0m was: 1 now: 1 #hooks: 0 upnp: 0 v:0xda51d0/NONE duplicate:1 <0x2bc55680>
02 04/09/14 20:00:01.370 e[33;1mZW_Send_Data node 2 NO ROUTE (nil)e[0m <0x2be55680>
06 04/09/14 20:00:01.498 Device_Variable::m_szValue_set device: 6 service: urn:micasaverde-com:serviceId:EnergyMetering1 variable: e[35;1mKWHe[0m was: 26.1260 now: 26.1330 #hooks: 0 upnp: 0 v:0xda4b60/NONE duplicate:0 <0x2bc55680>
06 04/09/14 20:00:01.498 Device_Variable::m_szValue_set device: 6 service: urn:micasaverde-com:serviceId:EnergyMetering1 variable: e[35;1mKWHReadinge[0m was: 1397066161 now: 1397066401 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:0 <0x2bc55680>
02 04/09/14 20:00:03.500 e[33;1mZW_Send_Data node 2 NO ROUTE (nil)e[0m <0x2be55680>
06 04/09/14 20:00:03.647 Device_Variable::m_szValue_set device: 6 service: urn:micasaverde-com:serviceId:EnergyMetering1 variable: e[35;1mWattse[0m was: 97 now: 97 #hooks: 0 upnp: 0 v:0xda5190/NONE duplicate:1 <0x2bc55680>
06 04/09/14 20:00:03.648 Device_Variable::m_szValue_set device: 6 service: urn:micasaverde-com:serviceId:EnergyMetering1 variable: e[35;1mActualUsagee[0m was: 1 now: 1 #hooks: 0 upnp: 0 v:0xda51d0/NONE duplicate:1 <0x2bc55680>
04 04/09/14 20:00:03.649 <Job ID="123" Name="pollnode #2 4 cmds" Device="6" Created="2014-04-09 19:59:57" Started="2014-04-09 19:59:57" Completed="2014-04-09 20:00:03" Duration="6.548083000" Runtime="6.546760000" Status="Successful" LastNote="" Node="2" NodeType="ZWaveDimmableLight" NodeDescription="Lounge Lights"/> <0x2bc55680>
06 04/09/14 20:00:11.957 Device_Variable::m_szValue_set device: 71 service: urn:micasaverde-com:serviceId:SecuritySensor1 variable: e[35;1mTrippede[0m was: 1 now: 1 #hooks: 2 upnp: 0 v:0xd6e2c8/NONE duplicate:0 <0x2bc55680>
07 04/09/14 20:00:11.958 Event::Evaluate 8 Bedroom PIR Triggered scene Bedroom lights on is true users:(null) allow:1 <0x2bc55680>
08 04/09/14 20:00:11.958 Scene::RunScene running 7 Bedroom lights on <0x2bc55680>
08 04/09/14 20:00:11.958 JobHandler_LuaUPnP::HandleActionRequest device: 69 service: urn:upnp-org:serviceId:Dimming1 action: e[36;1mSetLoadLevelTargete[0m <0x2bc55680>
08 04/09/14 20:00:11.959 JobHandler_LuaUPnP::HandleActionRequest argument newLoadlevelTarget=100 <0x2bc55680>
06 04/09/14 20:00:11.959 Device_Variable::m_szValue_set device: 69 service: urn:upnp-org:serviceId:Dimming1 variable: e[35;1mLoadLevelTargete[0m was: 100 now: 100 #hooks: 0 upnp: 0 v:0xd954f8/NONE duplicate:1 <0x2bc55680>
02 04/09/14 20:00:11.960 e[33;1mZWJob_SendData UPDATE MANUAL ROUTE 10=(nil)e[0m <0x2bc55680>
07 04/09/14 20:00:11.961 Event::Evaluate 9 Bedroom PIR off scene Bedroom Lights Off is false repeat 0/-1 <0x2bc55680>
06 04/09/14 20:00:11.961 Device_Variable::m_szValue_set device: 71 service: urn:micasaverde-com:serviceId:SecuritySensor1 variable: e[35;1mArmedTrippede[0m was: 1 now: 1 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:1 <0x2bc55680>
06 04/09/14 20:00:11.961 Device_Variable::m_szValue_set device: 71 service: urn:micasaverde-com:serviceId:SecuritySensor1 variable: e[35;1mLastTripe[0m was: 1397065873 now: 1397066411 #hooks: 0 upnp: 0 v:0xd73558/NONE duplicate:0 <0x2bc55680>
02 04/09/14 20:00:11.963 e[33;1mUPDATE MANUAL ROUTE2 10=(nil)e[0m <0x2be55680>
02 04/09/14 20:00:11.963 e[33;1mZW_Send_Data node 10 NO ROUTE (nil)e[0m <0x2be55680>
02 04/09/14 20:00:12.069 e[33;1mUPDATE MANUAL ROUTE2 10=(nil)e[0m <0x2be55680>
02 04/09/14 20:00:12.069 e[33;1mZW_Send_Data node 10 NO ROUTE (nil)e[0m <0x2be55680>
06 04/09/14 20:00:12.367 Device_Variable::m_szValue_set device: 69 service: urn:upnp-org:serviceId:Dimming1 variable: e[35;1mLoadLevelStatuse[0m was: 100 now: 100 #hooks: 4 upnp: 0 v:0xd8cb60/NONE duplicate:1 <0x2bc55680>
06 04/09/14 20:00:12.367 Device_Variable::m_szValue_set device: 69 service: urn:upnp-org:serviceId:SwitchPower1 variable: e[35;1mStatuse[0m was: 1 now: 1 #hooks: 0 upnp: 0 v:0xd89248/NONE duplicate:1 <0x2bc55680>
04 04/09/14 20:00:12.369 <Job ID="124" Name="Level 99 node 10" Device="69" Created="2014-04-09 20:00:11" Started="2014-04-09 20:00:11" Completed="2014-04-09 20:00:12" Duration="0.408767000" Runtime="0.406032000" Status="Successful" LastNote="Transmit was ok" Node="10" NodeType="ZWaveDimmableLight" NodeDescription="Bedroom"/> <0x2bc55680>
06 04/09/14 20:00:13.107 Device_Variable::m_szValue_set device: 70 service: urn:upnp-org:serviceId:SwitchPower1 variable: e[35;1mStatuse[0m was: 0 now: 1 #hooks: 0 upnp: 0 v:0xd89248/NONE duplicate:0 <0x2bc55680>
06 04/09/14 20:00:13.108 Device_Variable::m_szValue_set device: 70 service: urn:upnp-org:serviceId:Dimming1 variable: e[35;1mLoadLevelStatuse[0m was: 0 now: 100 #hooks: 1 upnp: 0 v:0xd8cb60/NONE duplicate:0 <0x2bc55680>
50 04/09/14 20:00:22.111 luup_log:42: Received: unknowncommand 14 <0x2f455680>
50 04/09/14 20:00:24.100 luup_log:94: Refreshing temperature. <0x2d855680>
50 04/09/14 20:00:24.356 luup_log:94: Status:0 <0x2d855680>
50 04/09/14 20:00:24.357 luup_log:94: Temperature string is:" 23.5" <0x2d855680>
50 04/09/14 20:00:24.357 luup_log:94: Temperature: 23.5 <0x2d855680>
06 04/09/14 20:00:24.358 Device_Variable::m_szValue_set device: 94 service: urn:upnp-org:serviceId:TemperatureSensor1 variable: e[35;1mCurrentTemperaturee[0m was: 23.5 now: 23.5 #hooks: 0 upnp: 0 v:0xd82cd8/NONE duplicate:1 <0x2d855680>
50 04/09/14 20:00:25.100 luup_log:96: Refreshing temperature. <0x2da55680>
50 04/09/14 20:00:25.388 luup_log:96: Status:0 <0x2da55680>
50 04/09/14 20:00:25.388 luup_log:96: Temperature string is:" 24" <0x2da55680>
50 04/09/14 20:00:25.388 luup_log:96: Temperature: 24 <0x2da55680>
06 04/09/14 20:00:25.389 Device_Variable::m_szValue_set device: 96 service: urn:upnp-org:serviceId:TemperatureSensor1 variable: e[35;1mCurrentTemperaturee[0m was: 24 now: 24 #hooks: 0 upnp: 0 v:0xd82cd8/NONE duplicate:1 <0x2da55680>
02 04/09/14 20:00:27.103 e[33;1mZW_Send_Data node 4 NO ROUTE (nil)e[0m <0x2be55680>
02 04/09/14 20:00:29.469 e[33;1mZW_Send_Data node 4 NO ROUTE (nil)e[0m <0x2be55680>
06 04/09/14 20:00:29.917 Device_Variable::m_szValue_set device: 97 service: urn:micasaverde-com:serviceId:EnergyMetering1 variable: e[35;1mWattse[0m was: 0 now: 109 #hooks: 0 upnp: 0 v:0xda5190/NONE duplicate:0 <0x2bc55680>
06 04/09/14 20:00:29.918 Device_Variable::m_szValue_set device: 97 service: urn:micasaverde-com:serviceId:EnergyMetering1 variable: e[35;1mLoge[0m was: 0,110,112,1397065949,1350 now: 109,81,112,1397066429,1830 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:0 <0x2bc55680>
06 04/09/14 20:00:29.918 Device_Variable::m_szValue_set device: 97 service: urn:micasaverde-com:serviceId:EnergyMetering1 variable: e[35;1mActualUsagee[0m was: 1 now: 1 #hooks: 0 upnp: 0 v:0xda51d0/NONE duplicate:1 <0x2bc55680>
02 04/09/14 20:00:31.920 e[33;1mZW_Send_Data node 4 NO ROUTE (nil)e[0m <0x2be55680>
06 04/09/14 20:00:32.398 Device_Variable::m_szValue_set device: 97 service: urn:micasaverde-com:serviceId:EnergyMetering1 variable: e[35;1mKWHe[0m was: 0.0620 now: 0.0640 #hooks: 0 upnp: 0 v:0xda4b60/NONE duplicate:0 <0x2bc55680>
06 04/09/14 20:00:32.398 Device_Variable::m_szValue_set device: 97 service: urn:micasaverde-com:serviceId:EnergyMetering1 variable: e[35;1mKWHReadinge[0m was: 1397066192 now: 1397066432 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:0 <0x2bc55680>
02 04/09/14 20:00:34.400 e[33;1mZW_Send_Data node 4 NO ROUTE (nil)e[0m <0x2be55680>
06 04/09/14 20:00:34.877 Device_Variable::m_szValue_set device: 97 service: urn:micasaverde-com:serviceId:EnergyMetering1 variable: e[35;1mWattse[0m was: 109 now: 109 #hooks: 0 upnp: 0 v:0xda5190/NONE duplicate:1 <0x2bc55680>
06 04/09/14 20:00:34.878 Device_Variable::m_szValue_set device: 97 service: urn:micasaverde-com:serviceId:EnergyMetering1 variable: e[35;1mActualUsagee[0m was: 1 now: 1 #hooks: 0 upnp: 0 v:0xda51d0/NONE duplicate:1 <0x2bc55680>
04 04/09/14 20:00:34.879 <Job ID="125" Name="pollnode #4 4 cmds" Device="97" Created="2014-04-09 20:00:27" Started="2014-04-09 20:00:27" Completed="2014-04-09 20:00:34" Duration="7.777901000" Runtime="7.776625000" Status="Successful" LastNote="" Node="4" NodeType="ZWaveDimmableLight" NodeDescription="Kitchen Light"/> <0x2bc55680>
02 04/09/14 20:00:57.102 e[33;1mZW_Send_Data node 5 NO ROUTE (nil)e[0m <0x2be55680>
01 04/09/14 20:00:57.978 e[31;1mluvd_get_info /etc/cmh-ludl/S_ProgramLogicEG.xml.lzo doesn't existe[0m <0x2f855680>
01 04/09/14 20:00:57.980 e[31;1mluvd_get_info /etc/cmh-ludl/S_ProgramLogicC.xml.lzo doesn't existe[0m <0x2f855680>
01 04/09/14 20:00:58.117 e[31;1mZWJob_PollNode::ReceivedFrame job job#126 :pollnode #5 dev:7 (0x1266088) N:5 P:100 S:5 got FUNC_ID_APPLICATION_COMMAND_HANDLER node info expected 5 got 3e[0m <0x2bc55680>
06 04/09/14 20:00:58.117 Device_Variable::m_szValue_set device: 4 service: urn:micasaverde-com:serviceId:SecuritySensor1 variable: e[35;1mTrippede[0m was: 1 now: 0 #hooks: 2 upnp: 0 v:0xd6e2c8/NONE duplicate:0 <0x2bc55680>
07 04/09/14 20:00:58.118 Event::Evaluate 1 Kitchen PIR triggered scene Switch on kitchen lights is false repeat 0/-1 <0x2bc55680>
07 04/09/14 20:00:58.118 Event::Evaluate 2 Kitchen PIR off scene Switch off kitchen lights is true users:(null) allow:1 <0x2bc55680>
08 04/09/14 20:00:58.118 Scene::RunScene running 2 Switch off kitchen lights <0x2bc55680>
08 04/09/14 20:00:58.119 JobHandler_LuaUPnP::HandleActionRequest device: 97 service: urn:upnp-org:serviceId:Dimming1 action: e[36;1mSetLoadLevelTargete[0m <0x2bc55680>
08 04/09/14 20:00:58.119 JobHandler_LuaUPnP::HandleActionRequest argument newLoadlevelTarget=0 <0x2bc55680>
06 04/09/14 20:00:58.119 Device_Variable::m_szValue_set device: 97 service: urn:upnp-org:serviceId:Dimming1 variable: e[35;1mLoadLevelTargete[0m was: 100 now: 0 #hooks: 0 upnp: 0 v:0xd954f8/NONE duplicate:0 <0x2bc55680>
02 04/09/14 20:00:58.120 e[33;1mZWJob_SendData UPDATE MANUAL ROUTE 4=(nil)e[0m <0x2bc55680>
06 04/09/14 20:00:58.122 Device_Variable::m_szValue_set device: 4 service: urn:micasaverde-com:serviceId:SecuritySensor1 variable: e[35;1mArmedTrippede[0m was: 1 now: 0 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:0 <0x2bc55680>
06 04/09/14 20:00:58.122 Device_Variable::m_szValue_set device: 4 service: urn:micasaverde-com:serviceId:SecuritySensor1 variable: e[35;1mLastTripe[0m was: 1397066370 now: 1397066458 #hooks: 0 upnp: 0 v:0xd73558/NONE duplicate:0 <0x2bc55680>
04 04/09/14 20:00:58.168 <Job ID="126" Name="pollnode #5 4 cmds" Device="7" Created="2014-04-09 20:00:57" Started="2014-04-09 20:00:57" Completed="2014-04-09 20:00:58" Duration="1.67070000" Runtime="1.66333000" Status="Aborted" LastNote="" Node="5" NodeType="ZWaveDimmableLight" NodeDescription="Dining Room Lights"/> <0x2bc55680>
02 04/09/14 20:00:58.170 e[33;1mUPDATE MANUAL ROUTE2 4=(nil)e[0m <0x2be55680>
02 04/09/14 20:00:58.171 e[33;1mZW_Send_Data node 4 NO ROUTE (nil)e[0m <0x2be55680>
02 04/09/14 20:00:58.279 e[33;1mUPDATE MANUAL ROUTE2 4=(nil)e[0m <0x2be55680>
02 04/09/14 20:00:58.279 e[33;1mZW_Send_Data node 4 NO ROUTE (nil)e[0m <0x2be55680>
06 04/09/14 20:01:00.257 Device_Variable::m_szValue_set device: 97 service: urn:upnp-org:serviceId:Dimming1 variable: e[35;1mLoadLevelStatuse[0m was: 100 now: 0 #hooks: 5 upnp: 0 v:0xd8cb60/NONE duplicate:0 <0x2bc55680>
06 04/09/14 20:01:00.258 Device_Variable::m_szValue_set device: 97 service: urn:upnp-org:serviceId:SwitchPower1 variable: e[35;1mStatuse[0m was: 1 now: 0 #hooks: 0 upnp: 0 v:0xd89248/NONE duplicate:0 <0x2bc55680>
04 04/09/14 20:01:00.259 <Job ID="127" Name="Level 0 node 4" Device="97" Created="2014-04-09 20:00:58" Started="2014-04-09 20:00:58" Completed="2014-04-09 20:01:00" Duration="2.138681000" Runtime="2.89400000" Status="Successful" LastNote="Transmit was ok" Node="4" NodeType="ZWaveDimmableLight" NodeDescription="Kitchen Light"/> <0x2bc55680>
50 04/09/14 20:01:22.111 luup_log:42: Received: unknowncommand 14 <0x2f455680>
The log shows that scene 1 was run when the PIR tripped and scene 2 was run when it un-tripped. Scene 1 turned the light on and scene 2 turned it off. No sign of delays.
How are you setting the delays for these scenes? If it is Lua code, post it so we can help diagnose the problem.
The 10 minute delay is done on the PIR itself. Parameter 18 is set to to the number of minutes you want to delay.
The weird thing is, the lights will go off while you are standing in front of the PIR, and movement won’t re-trigger it.
The log shows that the PIR un-tripped 1:28 after it tripped. If the PIR’s internal hold-time is set to ten minutes, something else must be changing the variable.
It 'should' get tripped, wait for no movement for 2 minutes, then delay by 10 minutes and then switch off.
What is the mechanism for this? If the PIR is holding-on for ten minutes, how are you detecting that there has been no movement for two minutes? What other scene actions and/or Lua are involved here?
The PIR is supposed to handle that, at least according to the documentation:
OFF/IDLE (Applicable only when the ZIR010 is configured for Lighting or Binary Sensor Mode).
The ZIR010 will consider there to be ?No Activity? after 2 minutes passes during which the ZIR010 detected no motion. At that point, the ZIR010 can be configured to immediately send the OFF or IDLE command or it can be configured to send it from 1 minute to 255 minutes later. (+/- 1 minute). [iurl=http://doc.eedomus.com/files/ZIR010_instr.pdf]http://doc.eedomus.com/files/ZIR010_instr.pdf[/iurl]
The setup on the Vera side is super simple. The PIR being triggered on is the trigger, and it runs Scene 1, which sets the kitchen lights on. PIR off is trigger for second scene, which sets Kitchen Lights to off.
The PIR is supposed to handle that, at least according to the documentation...
Well that isn’t what appears to be happening. Some possibilities:
[ul][li]Exclude and re-include the PIR. This will reset it to factory condition.[/li]
[li]Contact ACT for help in understanding why it isn’t working as you expect.[/li]
[li]If neither of the above help, use PLEG, PLTS or SmartSwitch to implement the timing.[/li][/ul]
Ok, thanks. Just wanted to make sure there wasn’t a network error causing the problem or something else that might have been logged.