We have moved at community.getvera.com

Author Topic: Waking up devices / Issue with thermostat setpoints  (Read 12017 times)

Offline ajlennon

  • Full Member
  • ***
  • Posts: 154
  • Karma: +0/-0
Re: Waking up devices / Issue with thermostat setpoints
« Reply #15 on: November 13, 2011, 08:27:31 am »

The Mantis engine seems not to want to email me an account activation, so I guess I'll have to wait...

Offline mcvflorin

  • Administrator
  • Hero Member
  • *****
  • Posts: 1755
  • Karma: +11/-3
Re: Waking up devices / Issue with thermostat setpoints
« Reply #16 on: November 14, 2011, 07:48:37 am »
Hi ajlennon,

Vera tells the thermostat to change its setpoint, and doesn't update its internal setpoint variable until it gets confirmation from the thermostat that the setpoint successfully changed. Maybe the thermostat isn't replying back its status? In your logs you don't have Z-Wave log lines (lines starting with 41 and 42) to see the messages exchanged between Vera and the thermostat, which would help finding the cause.

Offline ajlennon

  • Full Member
  • ***
  • Posts: 154
  • Karma: +0/-0
Re: Waking up devices / Issue with thermostat setpoints
« Reply #17 on: November 14, 2011, 09:04:58 am »
Hi mcvflorin (Florin?),

41,42 - useful to know thanks. Here's a new log of my attempt to change the SP from to 26. It updated in the thermostat but not the UI

Here's where I attempt to change the SP in the UI -

Code: [Select]
       luup_log:6: dataMine: Watching: D[5] S[urn:upnp-org:serviceId:TemperatureSensor1] V[CurrentTemperature] <0x402>
06      11/14/11 14:02:07.225   Device_Variable::m_szValue_set device: 6 service: urn:cd-jackson-com:serviceId:DataMine1 variable: ChannelCnt was: 3 now: 3 #hooks: 0 upnp: 0 v:0x7b9fd8/NONE duplicate:1 <0x402>
06      11/14/11 14:02:07.226   Device_Variable::m_szValue_set device: 6 service: urn:cd-jackson-com:serviceId:DataMine1 variable: ChannelRec was: 3 now: 3 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:1 <0x402>
02      11/14/11 14:02:20.015   ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
41      11/14/11 14:02:20.017   ZWaveSerial::Send XXXX  node 2 using route 0.0.40.137 autoroute: 1 direct: 0 <0xc04>
41      11/14/11 14:02:20.018   0x1 0xd 0x0 0x19 0x2 0x2 0x25 0x2 0x5 0x0 0x0 0x0 0x0 0x1 0xc8 (#\r####%########) <0xc04>
42      11/14/11 14:02:20.041   0x6 0x1 0x4 0x1 0x19 0x1 0xe2 (#######) <0x1406>
42      11/14/11 14:02:20.041   got expected ACK <0x1406>
41      11/14/11 14:02:20.042   ACK: 0x6 (#) <0x1406>
42      11/14/11 14:02:20.090   0x1 0x5 0x0 0x19 0x1 0x0 0xe2 (#######) <0x1406>
41      11/14/11 14:02:20.091   ACK: 0x6 (#) <0x1406>
42      11/14/11 14:02:20.141   0x1 0x9 0x0 0x4 0x0 0x2 0x3 0x25 0x3 0x0 0xd5 (#######%###) <0x1406>
41      11/14/11 14:02:20.142   ACK: 0x6 (#) <0x1406>
02      11/14/11 14:02:20.154   ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
41      11/14/11 14:02:20.155   ZWaveSerial::Send XXXX  node 2 using route 0.0.40.137 autoroute: 1 direct: 0 <0xc04>
41      11/14/11 14:02:20.156   0x1 0xd 0x0 0x19 0x2 0x2 0x40 0x2 0x5 0x0 0x0 0x0 0x0 0x2 0xae (#\r####@########) <0xc04>
08      11/14/11 14:02:20.168   JobHandler_LuaUPnP::HandleActionRequest device: 5 service: urn:upnp-org:serviceId:TemperatureSetpoint1_Heat action: SetCurrentSetpoint <0x4408>
08      11/14/11 14:02:20.169   JobHandler_LuaUPnP::HandleActionRequest argument DeviceNum=5 <0x4408>
08      11/14/11 14:02:20.170   JobHandler_LuaUPnP::HandleActionRequest argument serviceId=urn:upnp-org:serviceId:TemperatureSetpoint1_Heat <0x4408>
08      11/14/11 14:02:20.171   JobHandler_LuaUPnP::HandleActionRequest argument action=SetCurrentSetpoint <0x4408>
08      11/14/11 14:02:20.171   JobHandler_LuaUPnP::HandleActionRequest argument NewCurrentSetpoint=26 <0x4408>
08      11/14/11 14:02:20.172   JobHandler_LuaUPnP::HandleActionRequest argument rand=0.631132904025657 <0x4408>
06      11/14/11 14:02:20.173   Device_Variable::m_szValue_set device: 5 service: urn:upnp-org:serviceId:TemperatureSetpoint1_Heat variable: SetpointTarget was: 22 now: 26 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:0 <0x4408>
42      11/14/11 14:02:20.191   0x6 0x1 0x4 0x1 0x19 0x1 0xe2 (#######) <0x1406>
42      11/14/11 14:02:20.191   got expected ACK <0x1406>
41      11/14/11 14:02:20.192   ACK: 0x6 (#) <0x1406>
02      11/14/11 14:02:20.195   ZWJob_SendData  UPDATE MANUAL ROUTE 4=(nil) <0x4408>
41      11/14/11 14:02:20.202   0x1 0x3 0x0 0x16 0xea (#####) <0xc04>
42      11/14/11 14:02:20.241   0x1 0x5 0x0 0x19 0x2 0x0 0xe1 0x18 (########) <0x1406>
41      11/14/11 14:02:20.241   ACK: 0x6 (#) <0x1406>
01      11/14/11 14:02:20.251   got CAN <0x1406>
01      11/14/11 14:02:20.252   ZWaveSerial::Send m_iFrameID 29 type 0x0 command 0x16 got repeat failure 24 iNumFailedResponse 1 time 22251 start time 22210 wait 2000 m_iSendsWithoutReceive 0 <0xc04>
01      11/14/11 14:02:20.252   ZWaveJobHandler::SendDataAbort failed <0xc04>
01      11/14/11 14:02:20.253   ZWJob_PollNode::Run job job#2 :pollnode #2 (0x798820) N:2 P:100 S:1 ZW_Send_Data to node 2 failed 4 req (nil)/-1 abort m_iFrameID 0 <0xc04>
02      11/14/11 14:02:20.254   ZWJob_PollNode::PollFailed job job#2 :pollnode #2 (0x798820) N:2 P:100 S:1 node 2 battery 0 <0xc04>
06      11/14/11 14:02:20.255   Device_Variable::m_szValue_set device: 1 service: urn:micasaverde-com:serviceId:ZWaveNetwork1 variable: LastError was: Node 4 failed now: Poll failed #hooks: 0 upnp: 0 v:0x7f5d08/NONE duplicate:0 <0xc04>
04      11/14/11 14:02:20.258   <Job ID="2" Name="pollnode #2 2 cmds" Device="3" Created="11-11-14 14:02:20" Started="11-11-14 14:02:20" Completed="11-11-14 14:02:20" Duration="0.245098000" Runtime="0.242949000" Status="Failed" LastNote="" Node="2" NodeType="ZWaveThermostat" NodeDescription="Combi Boiler"/> <0xc04>
41      11/14/11 14:02:20.261   0x1 0x3 0x0 0x16 0xea (#####) <0x803>
42      11/14/11 14:02:20.291   0x1 0x9 0x0 0x4 0x0 0x2 0x3 0x40 0x3 0x0 0xb0 0x18 (#######@####) <0x1406>
41      11/14/11 14:02:20.292   ACK: 0x6 (#) <0x1406>
01      11/14/11 14:02:20.301   got CAN <0x1406>
01      11/14/11 14:02:20.302   ZWaveSerial::Send m_iFrameID 28 type 0x0 command 0x16 got repeat failure 24 iNumFailedResponse 1 time 22301 start time 22270 wait 2000 m_iSendsWithoutReceive 0 <0x803>
01      11/14/11 14:02:20.302   ZWJob_PollNode::Abort job job#2 :pollnode #2 (0x798820) N:2 P:100 S:2 to node 2 failed 2 <0x803>
02      11/14/11 14:02:20.304   JobHandler::PurgeCompletedJobs purge job#2 :pollnode #2 (0x798820) N:2 P:100 S:2 pollnode #2 2 cmds status 2 <0xc04>
02      11/14/11 14:02:20.307   UPDATE MANUAL ROUTE2 4=(nil) <0xc04>
02      11/14/11 14:02:20.308   ZW_Send_Data node 4 NO ROUTE (nil) <0xc04>
41      11/14/11 14:02:20.310   ZWaveSerial::Send XXXX  node 4 using route 0.101.32.35 autoroute: 1 direct: 0 <0xc04>
41      11/14/11 14:02:20.311   0x1 0x10 0x0 0x19 0x4 0x5 0x43 0x1 0x1 0x1 0x1a 0x5 0x0 0x0 0x0 0x0 0x3 0xa9 (######C###########) <0xc04>
42      11/14/11 14:02:20.341   0x6 0x1 0x4 0x1 0x19 0x1 0xe2 (#######) <0x1406>
42      11/14/11 14:02:20.341   got expected ACK <0x1406>
41      11/14/11 14:02:20.342   ACK: 0x6 (#) <0x1406>
42      11/14/11 14:02:20.471   0x1 0x5 0x0 0x19 0x3 0x6 0xe6 (#######) <0x1406>
41      11/14/11 14:02:20.471   ACK: 0x6 (#) <0x1406>
06      11/14/11 14:02:20.481   Device_Variable::m_szValue_set device: 5 service: urn:micasaverde-com:serviceId:HaDevice1 variable: CommFailure was: 0 now: 1 #hooks: 0 upnp: 0 v:0x79e478/NONE duplicate:0 <0x803>
06      11/14/11 14:02:20.483   Device_Variable::m_szValue_set device: 1 service: urn:micasaverde-com:serviceId:ZWaveNetwork1 variable: LastError was: Poll failed now: Node 4 failed #hooks: 0 upnp: 0 v:0x7f5d08/NONE duplicate:0 <0x803>
02      11/14/11 14:02:20.484   ZWJob_SendData::ReceivedFrame job job#3 :Heat SP 26 node 4 (0x81fcd8) N:4 P:35 S:5 to node 4 command 67/1 failed m_cTxStatus 6 retries 0 <0x803>
02      11/14/11 14:02:20.488   UPDATE MANUAL ROUTE2 4=(nil) <0xc04>
02      11/14/11 14:02:20.489   ZW_Send_Data node 4 NO ROUTE (nil) <0xc04>
41      11/14/11 14:02:20.491   ZWaveSerial::Send XXXX  node 4 using route 0.58.55.48 autoroute: 1 direct: 0 <0xc04>
41      11/14/11 14:02:20.492   0x1 0x10 0x0 0x19 0x4 0x5 0x43 0x1 0x1 0x1 0x1a 0x25 0x0 0x0 0x0 0x0 0x4 0x8e (######C####%######) <0xc04>
42      11/14/11 14:02:20.521   0x6 0x1 0x4 0x1 0x19 0x1 0xe2 (#######) <0x1406>
42      11/14/11 14:02:20.521   got expected ACK <0x1406>
41      11/14/11 14:02:20.522   ACK: 0x6 (#) <0x1406>
42      11/14/11 14:02:20.691   0x1 0x5 0x0 0x19 0x4 0x1 0xe6 (#######) <0x1406>
41      11/14/11 14:02:20.691   ACK: 0x6 (#) <0x1406>
02      11/14/11 14:02:20.701   ZWJob_SendData::ReceivedFrame job job#3 :Heat SP 26 node 4 (0x81fcd8) N:4 P:70 S:5 to node 4 command 67/1 failed m_cTxStatus 1 retries 1 <0x803>
02      11/14/11 14:02:20.705   UPDATE MANUAL ROUTE2 4=(nil) <0xc04>
02      11/14/11 14:02:20.706   ZW_Send_Data node 4 NO ROUTE (nil) <0xc04>
41      11/14/11 14:02:20.708   ZWaveSerial::Send XXXX  node 4 using route 0.58.55.48 autoroute: 1 direct: 0 <0xc04>
41      11/14/11 14:02:20.709   0x1 0x10 0x0 0x19 0x4 0x5 0x43 0x1 0x1 0x1 0x1a 0x25 0x0 0x0 0x0 0x0 0x5 0x8f (######C####%######) <0xc04>
42      11/14/11 14:02:20.740   0x6 0x1 0x4 0x1 0x19 0x1 0xe2 (#######) <0x1406>
42      11/14/11 14:02:20.741   got expected ACK <0x1406>
41      11/14/11 14:02:20.742   ACK: 0x6 (#) <0x1406>
42      11/14/11 14:02:20.961   0x1 0x5 0x0 0x19 0x5 0x1 0xe7 (#######) <0x1406>
41      11/14/11 14:02:20.961   ACK: 0x6 (#) <0x1406>
02      11/14/11 14:02:20.971   ZWJob_SendData::ReceivedFrame job job#3 :Heat SP 26 node 4 (0x81fcd8) N:4 P:70 S:5 to node 4 command 67/1 failed m_cTxStatus 1 retries 2 <0x803>
02      11/14/11 14:02:20.975   UPDATE MANUAL ROUTE2 4=(nil) <0xc04>
02      11/14/11 14:02:20.976

And here's where it actually changes when the thermostat wakes up

Code: [Select]
02      11/14/11 14:03:50.183   ZW_Send_Data node 2 NO ROUTE (nil) <0xc04>
41      11/14/11 14:03:50.184   ZWaveSerial::Send XXXX  node 2 using route 0.0.44.184 autoroute: 1 direct: 0 ... <0xc04>
41      11/14/11 14:03:50.186   0x1 0xd 0x0 0x19 0x2 0x2 0x40 0x2 0x5 0x0 0x0 0x0 0x0 0xa 0xa6 (#\r####@######\n#) <0xc04>
42      11/14/11 14:03:50.221   0x6 0x1 0x4 0x1 0x19 0x1 0xe2 (#######) <0x1406>
42      11/14/11 14:03:50.221   got expected ACK <0x1406>
41      11/14/11 14:03:50.222   ACK: 0x6 (#) <0x1406>
42      11/14/11 14:03:50.270   0x1 0x5 0x0 0x19 0xa 0x0 0xe9 (####\n##) <0x1406>
41      11/14/11 14:03:50.271   ACK: 0x6 (#) <0x1406>
42      11/14/11 14:03:50.321   0x1 0x9 0x0 0x4 0x0 0x2 0x3 0x40 0x3 0x0 0xb0 (#######@###) <0x1406>
41      11/14/11 14:03:50.321   ACK: 0x6 (#) <0x1406>
04      11/14/11 14:03:50.333   <Job ID="4" Name="pollnode #2 2 cmds" Device="3" Created="11-11-14 14:03:50" Started="11-11-14 14:03:50" Completed="11-11-14 14:03:50" Duration="0.321132000" Runtime="0.319539000" Status="Successful" LastNote="" Node="2" NodeType="ZWaveThermostat" NodeDescription="Combi Boiler"/> <0x803>
02      11/14/11 14:04:16.123   UPnPCallbackEventHandler 6 start PIDLOG2 20580 <0x2009>
42      11/14/11 14:04:16.801   0x1 0x8 0x0 0x4 0x0 0x4 0x2 0x84 0x7 0x76 (#########v) <0x1406>
41      11/14/11 14:04:16.802   ACK: 0x6 (#) <0x1406>
06      11/14/11 14:04:16.811   Device_Variable::m_szValue_set device: 5 service: urn:micasaverde-com:serviceId:ZWaveDevice1 variable: LastWakeup was: 1321279200 now: 1321279456 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:0 <0x803>
02      11/14/11 14:04:16.814   ZWJob_SendData  UPDATE MANUAL ROUTE 4=(nil) <0x803>
02      11/14/11 14:04:16.815   ZWaveNode::Wakeup did a poll for 4 256 seconds existing (nil) heal (nil) <0x803>
02      11/14/11 14:04:16.816   ZWJob_SendData  UPDATE MANUAL ROUTE 4=(nil) <0x803>
02      11/14/11 14:04:16.834   UPDATE MANUAL ROUTE2 4=(nil) <0xc04>
02      11/14/11 14:04:16.835   ZW_Send_Data node 4 NO ROUTE (nil) <0xc04>
41      11/14/11 14:04:16.836   ZWaveSerial::Send XXXX  node 4 using route 0.0.49.52 autoroute: 1 direct: 0 <0xc04>
41      11/14/11 14:04:16.837   0x1 0x10 0x0 0x19 0x4 0x5 0x43 0x1 0x1 0x1 0x1a 0x5 0x0 0x0 0x0 0x0 0xb 0xa1 (######C###########) <0xc04>
42      11/14/11 14:04:16.851   0x6 0x1 0x4 0x1 0x19 0x1 0xe2 (#######) <0x1406>
42      11/14/11 14:04:16.851   got expected ACK <0x1406>
41      11/14/11 14:04:16.852   ACK: 0x6 (#) <0x1406>
42      11/14/11 14:04:16.911   0x1 0x5 0x0 0x19 0xb 0x0 0xe8 (#######) <0x1406>
41      11/14/11 14:04:16.911   ACK: 0x6 (#) <0x1406>
06      11/14/11 14:04:16.921   Device_Variable::m_szValue_set device: 5 service: urn:micasaverde-com:serviceId:HaDevice1 variable: CommFailure was: 1 now: 0 #hooks: 0 upnp: 0 v:0x79e478/NONE duplicate:0 <0x803>
06      11/14/11 14:04:16.922   Device_Variable::m_szValue_set device: 1 service: urn:micasaverde-com:serviceId:ZWaveNetwork1 variable: LastError was: Node 4 failed now: Node 4 failed #hooks: 0 upnp: 0 v:0x7f5d08/NONE duplicate:1 <0x803>
04      11/14/11 14:04:16.925   <Job ID="5" Name="send failed node 4" Device="5" Created="11-11-14 14:04:16" Started="11-11-14 14:04:16" Completed="11-11-14 14:04:16" Duration="0.110942000" Runtime="0.103293000" Status="Successful" LastNote="Transmit was ok" Node="4" NodeType="ZWaveThermostat" NodeDescription="_Thermostat"/> <0x803>
02      11/14/11 14:04:16.929   UPDATE MANUAL ROUTE2 4=(nil) <0xc04>
02      11/14/11 14:04:16.931   ZW_Send_Data node 4 NO ROUTE (nil) <0xc04>
41      11/14/11 14:04:16.933   ZWaveSerial::Send XXXX  node 4 using route 0.0.88.14 autoroute: 1 direct: 0 <0xc04>
41      11/14/11 14:04:16.934   0x1 0xd 0x0 0x19 0x4 0x2 0x84 0x8 0x5 0x0 0x0 0x0 0x0 0xc 0x68 (#\r############h) <0xc04>
42      11/14/11 14:04:16.961   0x6 0x1 0x4 0x1 0x19 0x1 0xe2 (#######) <0x1406>
42      11/14/11 14:04:16.961   got expected ACK <0x1406>
41      11/14/11 14:04:16.962   ACK: 0x6 (#) <0x1406>
42      11/14/11 14:04:17.011   0x1 0x5 0x0 0x19 0xc 0x0 0xef (#######) <0x1406>
41      11/14/11 14:04:17.011   ACK: 0x6 (#) <0x1406>
04      11/14/11 14:04:17.024   <Job ID="6" Name="Wakeup done 4" Device="5" Created="11-11-14 14:04:16" Started="11-11-14 14:04:16" Completed="11-11-14 14:04:17" Duration="0.206535000" Runtime="0.94609000" Status="Successful" LastNote="Transmit was ok" Node="4" NodeType="ZWaveThermostat" NodeDescription="_Thermostat"/>^[[5~

Offline ajlennon

  • Full Member
  • ***
  • Posts: 154
  • Karma: +0/-0
Re: Waking up devices / Issue with thermostat setpoints
« Reply #18 on: November 15, 2011, 06:08:28 am »

All of a sudden overnight Vera 2 is no longer communicating with either the boiler actuator or the thermostat (!)

I'm getting various messages from the UI in including "unable to communicate with node" and turn heating on or off

I've tried healing the network.

The logs seem to be saying something about the actuator not being configured!

Code: [Select]
02      11/15/11 11:03:13.011   UPnPCallbackEventHandler 7 start PIDLOG2 7265 <0x300d>
08      11/15/11 11:04:38.010   Scene::RunScene running 3 Heating <0x803>
50      11/15/11 11:04:38.012   luup_log:0: Heating SetPoint = 19 <0x803>
50      11/15/11 11:04:38.013   luup_log:0: Temperature = 19 <0x803>
50      11/15/11 11:04:38.013   luup_log:0: Heating already off <0x803>
08      11/15/11 11:04:38.014   JobHandler_LuaUPnP::AlarmCallback Ran timer: Four Minute next at 1321355318 now 1321355078 <0x803>
08      11/15/11 11:07:17.928   JobHandler_LuaUPnP::HandleActionRequest device: 3 service: urn:upnp-org:serviceId:HVAC_UserOperatingMode1 action: SetModeTarget <0x5408>
08      11/15/11 11:07:17.929   JobHandler_LuaUPnP::HandleActionRequest argument DeviceNum=3 <0x5408>
08      11/15/11 11:07:17.930   JobHandler_LuaUPnP::HandleActionRequest argument serviceId=urn:upnp-org:serviceId:HVAC_UserOperatingMode1 <0x5408>
08      11/15/11 11:07:17.931   JobHandler_LuaUPnP::HandleActionRequest argument action=SetModeTarget <0x5408>
08      11/15/11 11:07:17.931   JobHandler_LuaUPnP::HandleActionRequest argument NewModeTarget=HeatOn <0x5408>
08      11/15/11 11:07:17.932   JobHandler_LuaUPnP::HandleActionRequest argument rand=0.6412345498113862 <0x5408>
02      11/15/11 11:07:17.970   ZWaveThermostat::ReceivedMessage no COMMAND_CLASS_THERMOSTAT_MODE <0x5408>
02      11/15/11 11:07:17.971   ZWaveNode::ReceivedMessage serv urn:upnp-org:serviceId:HVAC_UserOperatingMode1 action SetModeTarget unhandled <0x5408>
02      11/15/11 11:07:17.971   JobHandler_LuaUPnP::RunAction device 3 action urn:upnp-org:serviceId:HVAC_UserOperatingMode1/SetModeTarget failed with -911/ERROR Thermostat is not configured <0x5408>
08      11/15/11 11:07:21.207   JobHandler_LuaUPnP::HandleActionRequest device: 3 service: urn:upnp-org:serviceId:HVAC_UserOperatingMode1 action: SetModeTarget <0x5408>
08      11/15/11 11:07:21.208   JobHandler_LuaUPnP::HandleActionRequest argument DeviceNum=3 <0x5408>
08      11/15/11 11:07:21.208   JobHandler_LuaUPnP::HandleActionRequest argument serviceId=urn:upnp-org:serviceId:HVAC_UserOperatingMode1 <0x5408>
08      11/15/11 11:07:21.209   JobHandler_LuaUPnP::HandleActionRequest argument action=SetModeTarget <0x5408>
08      11/15/11 11:07:21.209   JobHandler_LuaUPnP::HandleActionRequest argument NewModeTarget=HeatOn

I'm baffled as to what changed overnight. Any ideas?

Offline oTi@

  • Community Beta
  • Master Member
  • ******
  • Posts: 4041
  • Karma: +32/-6
  • UI what ?!
Re: Waking up devices / Issue with thermostat setpoints
« Reply #19 on: November 15, 2011, 06:30:58 am »
I'm baffled as to what changed overnight. Any ideas?
Is there a repair report for 2am this morning? (Z-Wave device > Repair)
Dezwaved at the moment...

Offline ajlennon

  • Full Member
  • ***
  • Posts: 154
  • Karma: +0/-0
Re: Waking up devices / Issue with thermostat setpoints
« Reply #20 on: November 15, 2011, 06:41:54 am »
No there's only one from later on in the morning after I initiated it to try to fix the problem -

Code: [Select]
11-11-15 10:51:36 report for HealNetwork.  Successful: Y Updated net: N  mr_only:0 Job ID: job#64 :heal network (0x785a98) P:71 S:5



=======NEIGHBOR NODE UPDATES=======
Node 2 Device 3 Combi Boiler neighbor nodes updated 0 times (incomplete 5 in a row 0), woke up 0 times configured: NO
Node 4 Device 5 _Thermostat neighbor nodes updated 0 times (incomplete 1 in a row 0), woke up 1 times configured: NO


=======STRESS TEST RESULT=======
Node 2 Device 3 Combi Boiler
  Test: NOP Sent 2 test frames and 0 succeeded (0%) with average of 0.000000 seconds and maximum of 0.000000 seconds
  Test: Basic_Get Sent 2 test frames and 0 succeeded (0%) with average of 0.000000 seconds and maximum of 0.000000 seconds
  Test: Get Node Info  Sent 2 test frames and 0 succeeded (0%) with average of 0.000000 seconds and maximum of 0.000000 seconds
  --HEALTH SCORE: 0--


=======NEIGHBOR NODE RESULT=======
Node 2 Device 3 Combi Boiler took 0.64126000 seconds to report neighbors:
Node 4 Device 5 _Thermostat took 0.36870000 seconds to report neighbors:

Inversely:


=======EDGE NODE PROFILE=======



=======DETAILED LOG=======
--Stage #1 started: 11-11-15 10:51:36 completed: 11-11-15 10:51:36 successful: N
---11-11-15 10:47:06 Job unknown
--Stage #2 started: 11-11-15 10:47:06 completed: 11-11-15 10:51:36 successful: Y
---11-11-15 10:47:06 Pass 0/5 Updating neighbors for node 2
---11-11-15 10:47:13 Job job#65 :heal_neighbor_node 2 (0x7ea5c8) P:70 S:4 was Successful
---11-11-15 10:47:13 Pass 0/5 Updating neighbors for node 4
---11-11-15 10:47:14 Job job#66 :heal_neighbor_node 4 (0x79e218) P:70 S:4 was Successful
---11-11-15 10:47:14 Pass 1/5 Updating neighbors for node 2
---11-11-15 10:47:21 Job job#67 :heal_neighbor_node 2 (0x784680) P:70 S:4 was Successful
---11-11-15 10:47:21 Pass 2/5 Updating neighbors for node 2
---11-11-15 10:47:29 Job job#68 :heal_neighbor_node 2 (0x769fc8) P:70 S:4 was Successful
---11-11-15 10:47:29 Pass 3/5 Updating neighbors for node 2
---11-11-15 10:47:37 Job job#69 :heal_neighbor_node 2 (0x7b9f38) P:70 S:4 was Successful
---11-11-15 10:47:37 Pass 4/5 Updating neighbors for node 2
---11-11-15 10:47:45 Job job#70 :heal_neighbor_node 2 (0x8273c0) P:70 S:4 was Successful
---11-11-15 10:47:45 Neighbor Update Done
--Stage #3 started: 11-11-15 10:47:45 completed: 11-11-15 10:51:36 successful: Y
---11-11-15 10:47:45 Routing update node 2
---11-11-15 10:47:45 Job job#71 :heal_routing_node 2 (0x7a9528) P:70 S:4 was Successful
---11-11-15 10:47:45 Routing update node 4
---11-11-15 10:47:45 Job job#72 :heal_routing_node 4 (0x828890) P:70 S:4 was Successful
---11-11-15 10:47:45 Routing update done
--Stage #4 started: 11-11-15 10:51:36 completed: 11-11-15 10:51:36 successful: Y
---11-11-15 10:47:46 Calculate Routes Done
--Stage #5 started: 11-11-15 10:47:46 completed: 11-11-15 10:51:36 successful: Y
---11-11-15 10:47:46 Configure node 2
---11-11-15 10:47:56 Job job#73 :conf_jh#2 (0x828bc0) P:70 S:3 was Aborted: Unable to get any information on node
---11-11-15 10:47:56 Configure node 4
---11-11-15 10:48:07 Job job#75 :conf_jh#4 (0x826680) P:70 S:3 was Aborted: Unable to get any information on node
---11-11-15 10:48:07 Configure Done
--Stage #6 started: 11-11-15 10:50:19 completed: 11-11-15 10:51:36 successful: Y
---11-11-15 10:50:19 Node 4 woke up
---11-11-15 10:50:19 Pass 5/5 Updating neighbors for node 4
---11-11-15 10:51:07 Battery devices awoke
--Stage #7 started: 11-11-15 10:51:07 completed: 11-11-15 10:51:36 successful: Y
---11-11-15 10:51:11 Node Details heal 2
---11-11-15 10:51:25 Node Details heal 2
---11-11-15 10:51:36 Stress test Done

That said I have rebooted the box a couple of times since then. I don't know if that would delete them?

Offline ajlennon

  • Full Member
  • ***
  • Posts: 154
  • Karma: +0/-0
Re: Waking up devices / Issue with thermostat setpoints
« Reply #21 on: November 15, 2011, 09:26:46 am »

Very very strange. The errors from the boiler actuator were related to it not being configured (although it was fine yesterday).

After I ran the heal I was still getting those errors so I caused the UI to "configure node now" which it did.

After that it was fine! Can't understand why it thought it was no longer configured...

Offline mcvflorin

  • Administrator
  • Hero Member
  • *****
  • Posts: 1755
  • Karma: +11/-3
Re: Waking up devices / Issue with thermostat setpoints
« Reply #22 on: November 15, 2011, 11:26:53 am »
41      11/14/11 14:02:20.311   0x1 0x10 0x0 0x19 0x41 0x5 0x432 0x1 0x1 0x1 0x1a3 0x5 0x0 0x0 0x0 0x0 0x3 0xa9 (######C###########) <0xc04>

41      11/14/11 14:02:20.492   0x1 0x10 0x0 0x19 0x4 0x5 0x43 0x1 0x1 0x1 0x1a 0x25 0x0 0x0 0x0 0x0 0x4 0x8e (######C####%######) <0xc04>

41      11/14/11 14:02:20.709   0x1 0x10 0x0 0x19 0x4 0x5 0x43 0x1 0x1 0x1 0x1a 0x25 0x0 0x0 0x0 0x0 0x5 0x8f (######C####%######) <0xc04>

02      11/14/11 14:02:20.971   ZWJob_SendData::ReceivedFrame job job#3 :Heat SP 26 node 4 (0x81fcd8) N:4 P:70 S:5 to node 4 command 67/1 failed m_cTxStatus 1 retries 2 <0x803>


From what I can tell from the logs Vera sent a command of class 0x432 with the new setpoint of 26(0x1a)3 to node 41. It sent the message once (311), then retried twice (at 492 and 709) and eventually it concluded that the new setpoint wasn't set (971). I don't know why this happened (maybe it didn't receive what it expected from the thermostat?), but it seems that this is the reason why Vera is not updating the setpoint variable. I will try to find more about this.


Offline oTi@

  • Community Beta
  • Master Member
  • ******
  • Posts: 4041
  • Karma: +32/-6
  • UI what ?!
Re: Waking up devices / Issue with thermostat setpoints
« Reply #23 on: November 15, 2011, 12:22:21 pm »
@mcvflorin,

I think that's the sequence for when the t-stat is still sleeping. A little later (14:04:16.837) the command does seem to go through when the t-stat is awake and the comm failure is cleared, and I believe the OP was seeing 'transmit ok' and a changed setpoint on the t-stat itself.
Dezwaved at the moment...

Offline ajlennon

  • Full Member
  • ***
  • Posts: 154
  • Karma: +0/-0
Re: Waking up devices / Issue with thermostat setpoints
« Reply #24 on: November 15, 2011, 12:24:03 pm »

Thanks Florin / oti@

Offline ajlennon

  • Full Member
  • ***
  • Posts: 154
  • Karma: +0/-0
Re: Waking up devices / Issue with thermostat setpoints
« Reply #25 on: November 15, 2011, 01:13:39 pm »

Florin,

I think it as oti@ suggests. It does retry a few times then fail as the thermostat is asleep. Then it waits and retries as below -

Code: [Select]
02      11/15/11 18:05:36.724   ZWaveNode::Wakeup did a poll for 4 256 seconds existing (nil) heal (nil) <0x803>
02      11/15/11 18:05:36.726   ZWJob_SendData  UPDATE MANUAL ROUTE 4=(nil) <0x803>
02      11/15/11 18:05:36.743   UPDATE MANUAL ROUTE2 4=(nil) <0xc04>
02      11/15/11 18:05:36.744   ZW_Send_Data node 4 NO ROUTE (nil) <0xc04>
41      11/15/11 18:05:36.746   ZWaveSerial::Send XXXX  node 4 using route 0.32.80.58 autoroute: 1 direct: 0 <0xc04>
[color=red]41      11/15/11 18:05:36.747   0x1 0x10 0x0 0x19 0x4 0x5 0x43 0x1 0x1 0x1 0x16 0x5 0x0 0x0 0x0 0x0 0x14 0xb2 (######C###########) <0xc04>
[/color]42      11/15/11 18:05:36.791   0x6 0x1 0x4 0x1 0x19 0x1 0xe2 (#######) <0x1406>
42      11/15/11 18:05:36.791   got expected ACK <0x1406>
41      11/15/11 18:05:36.792   ACK: 0x6 (#) <0x1406>
42      11/15/11 18:05:36.841   0x1 0x5 0x0 0x19 0x14 0x0 0xf7 (#######) <0x1406>
41      11/15/11 18:05:36.841   ACK: 0x6 (#) <0x1406>
06      11/15/11 18:05:36.851   Device_Variable::m_szValue_set device: 5 service: urn:micasaverde-com:serviceId:HaDevice1 variable: CommFailure was: 1 now: 0 #hooks: 0 upnp: 0 v:0x828b38/NONE duplicate:0 <0x803>
06      11/15/11 18:05:36.852   Device_Variable::m_szValue_set device: 1 service: urn:micasaverde-com:serviceId:ZWaveNetwork1 variable: LastError was: Node 4 failed now: Node 4 failed #hooks: 0 upnp: 0 v:0x8289a8/NONE duplicate:1 <0x803>
[color=red]04      11/15/11 18:05:36.855   <Job ID="11" Name="send failed node 4" Device="5" Created="11-11-15 18:05:36" Started="11-11-15 18:05:36" Completed="11-11-15 18:05:36" Duration="0.131155000" Runtime="0.112545000" Status="Successful" LastNote="Transmit was ok" Node="4" NodeType="ZWaveThermostat" NodeDescription="_Thermostat"/> <0x803>
[/color]02      11/15/11 18:05:36.861   UPDATE MANUAL ROUTE2 4=(nil) <0xc04>
02      11/15/11 18:05:36.862   ZW_Send_Data node 4 NO ROUTE (nil) <0xc04>

Going back to your earlier comment
Quote
Vera tells the thermostat to change its setpoint, and doesn't update its internal setpoint variable until it gets confirmation from the thermostat that the setpoint successfully changed. Maybe the thermostat isn't replying back its status?

We're seeing the success ACK come back I think, and Vera is updating its status to "Successful" so shouldn't it also be updating its internal setpoint at this time?

Cheers,

Alex/

Offline intveltr

  • Beta Testers
  • Hero Member
  • *****
  • Posts: 1741
  • Karma: +102/-5
Re: Waking up devices / Issue with thermostat setpoints
« Reply #26 on: November 16, 2011, 05:52:50 pm »
For now, I'm using a crappy workaround to get the GUI to update correctly.  It requires LUA code but I am using that anyway.  I have a virtual thermostat that holds the default day temperature; so that I can easily change the default temperature by changing the virtual device rather than going through scenes to change hardcoded values.  When I return home or in the morning when the timer fires, this scene copies the temperature set in the virtual thermostat to the actual device.  There are two commands, one to send the new temp setpoint to the thermostat, and the other to set the local setpoint (which is what Vera displays).

Code: [Select]
local DEVICE_HUISKAMER = 91
local DEFAULT_HUISKAMER = 95

local t_huis = luup.variable_get("urn:upnp-org:serviceId:TemperatureSetpoint1_Heat", "CurrentSetpoint", DEFAULT_HUISKAMER)
luup.variable_set("urn:upnp-org:serviceId:TemperatureSetpoint1_Heat", "CurrentSetpoint", t_huis, DEVICE_HUISKAMER)
luup.call_action ("urn:upnp-org:serviceId:TemperatureSetpoint1_Heat", "SetCurrentSetpoint", {NewCurrentSetpoint = t_huis}, DEVICE_HUISKAMER)

HomeWave is available in the App Store!  Turn your iPhone/iPad into an easy-to-use remote control for Vera.

Offline utz

  • Sr. Member
  • ****
  • Posts: 274
  • Karma: +0/-0
Re: Waking up devices / Issue with thermostat setpoints
« Reply #27 on: January 04, 2012, 04:45:03 pm »
I am stuck at that point now too. Where is the code that processes the ACK so we could maybe fix this? Any idea?

Offline Ap15e

  • Beta Testers
  • Hero Member
  • *****
  • Posts: 1998
  • Karma: +12/-0
Re: Waking up devices / Issue with thermostat setpoints
« Reply #28 on: January 05, 2012, 01:22:26 pm »
Quote
Where is the code that processes the ACK so we could maybe fix this?

In LuaUPnP?

Offline utz

  • Sr. Member
  • ****
  • Posts: 274
  • Karma: +0/-0
Re: Waking up devices / Issue with thermostat setpoints
« Reply #29 on: January 05, 2012, 01:27:38 pm »
In LuaUPnP?

Can you be a bit more precise? I am not familiar with the internal structure of vera. I know about files you need for a plugin and generally there would be an implementation file I_xxx. I am just not sure where this would be for the Thermostat device. Any pointer where to start looking (directory, filename, ...)

Thanks,

Utz