ZWave SetPoint Race Condition?

Configuration Z-Wave
1

Hello all!

I have been building up my first HA install and I am running across an odd issue.

I have a CT30 (crap I know… but it is what I have) that appears to not want to accept a new set point.

However if I look at the OZW log it looks like there is some sort of race condition between the set and get commands fired after a setpoint.

If I fire multiple ‘client.set_temperature’ commands then the setpoint will be updated. Mode changes (heat/off) reflect immediately.

Here is a snippet of the OZW log where one command attempts to set it to 66 (and fails, reporting the current temp as 65) then the command immediately after it that succeeds in updating the setpoint to 66.

2018-01-05 10:09:09.162 Info, Node028, Sending (Send) message (Callback ID=0x32, Expected Reply=0x13) - ThermostatSetpointCmd_Set (Node=28):
     0x01, 0x0c, 0x00, 0x13, 0x1c, 0x05, 0x43, 0x01, 0x01, 0x09, 0x42, 0x25, 0x32, 0xe6
    2018-01-05 10:09:09.170 Detail, Node028,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
    2018-01-05 10:09:09.170 Detail, Node028,   ZW_SEND_DATA delivered to Z-Wave stack
    2018-01-05 10:09:09.188 Detail, Node028,   Received: 0x01, 0x07, 0x00, 0x13, 0x32, 0x00, 0x00, 0x03, 0xda
    2018-01-05 10:09:09.188 Detail, Node028,   ZW_SEND_DATA Request with callback ID 0x32 received (expected 0x32)
    2018-01-05 10:09:09.188 Info, Node028, Request RTT 25 Average Request RTT 186
    2018-01-05 10:09:09.188 Detail,   Expected callbackId was received
    2018-01-05 10:09:09.188 Detail,   Expected reply was received
    2018-01-05 10:09:09.188 Detail,   Message transaction complete
    2018-01-05 10:09:09.188 Detail,
    2018-01-05 10:09:09.188 Detail, Node028, Removing current message
    2018-01-05 10:09:09.188 Detail,
    2018-01-05 10:09:09.188 Info, Node028, Sending (Send) message (Callback ID=0x33, Expected Reply=0x04) - ThermostatSetpointCmd_Get (Node=28): 0x01, 0x0a, 0x00, 0x13, 0x1c, 0x03, 0x43, 0x02, 0x01, 0x25, 0x33, 0xaf
    2018-01-05 10:09:09.195 Detail, Node028,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
    2018-01-05 10:09:09.195 Detail, Node028,   ZW_SEND_DATA delivered to Z-Wave stack
    2018-01-05 10:09:09.213 Detail, Node028,   Received: 0x01, 0x07, 0x00, 0x13, 0x33, 0x00, 0x00, 0x02, 0xda
    2018-01-05 10:09:09.213 Detail, Node028,   ZW_SEND_DATA Request with callback ID 0x33 received (expected 0x33)
    2018-01-05 10:09:09.213 Info, Node028, Request RTT 25 Average Request RTT 105
    2018-01-05 10:09:09.213 Detail,   Expected callbackId was received
    2018-01-05 10:09:09.255 Detail, Node028,   Received: 0x01, 0x0b, 0x00, 0x04, 0x00, 0x1c, 0x05, 0x43, 0x03, 0x01, 0x09, 0x41, 0xe0
    2018-01-05 10:09:09.255 Detail,
    2018-01-05 10:09:09.255 Info, Node028, Response RTT 66 Average Response RTT 68
    2018-01-05 10:09:09.255 Detail, Node028, Refreshed Value: old value=65, new value=65, type=decimal
    2018-01-05 10:09:09.255 Detail, Node028, Changes to this value are not verified
    2018-01-05 10:09:09.255 Info, Node028, Received thermostat setpoint report: Setpoint Heating 1 = 65F
    2018-01-05 10:09:09.255 Detail, Node028,   Expected reply and command class was received
    2018-01-05 10:09:09.255 Detail, Node028,   Message transaction complete
    2018-01-05 10:09:09.255 Detail,
    2018-01-05 10:09:09.255 Detail, Node028, Removing current message
    2018-01-05 10:09:09.255 Detail, Node028, Notification: ValueChanged
    2018-01-05 10:09:12.802 Info, Node028, Value::Set - COMMAND_CLASS_THERMOSTAT_SETPOINT - Heating 1 - 1 - 1 - 66
    2018-01-05 10:09:12.802 Detail, Node028, Queuing (Send) ThermostatSetpointCmd_Set (Node=28): 0x01, 0x0c, 0x00, 0x13, 0x1c, 0x05, 0x43, 0x01, 0x01, 0x09, 0x42, 0x25, 0x34, 0xe0
    2018-01-05 10:09:12.802 Detail, Node028, Queuing (Send) ThermostatSetpointCmd_Get (Node=28): 0x01, 0x0a, 0x00, 0x13, 0x1c, 0x03, 0x43, 0x02, 0x01, 0x25, 0x35, 0xa9
    2018-01-05 10:09:12.802 Detail,
    2018-01-05 10:09:12.802 Info, Node028, Sending (Send) message (Callback ID=0x34, Expected Reply=0x13) - ThermostatSetpointCmd_Set (Node=28): 0x01, 0x0c, 0x00, 0x13, 0x1c, 0x05, 0x43, 0x01, 0x01, 0x09, 0x42, 0x25, 0x34, 0xe0
    2018-01-05 10:09:12.811 Detail, Node028,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
    2018-01-05 10:09:12.811 Detail, Node028,   ZW_SEND_DATA delivered to Z-Wave stack
    2018-01-05 10:09:14.075 Detail, Node028,   Received: 0x01, 0x07, 0x00, 0x13, 0x34, 0x00, 0x00, 0x7f, 0xa0
    2018-01-05 10:09:14.075 Detail, Node028,   ZW_SEND_DATA Request with callback ID 0x34 received (expected 0x34)
    2018-01-05 10:09:14.075 Info, Node028, Request RTT 1273 Average Request RTT 689
    2018-01-05 10:09:14.075 Detail,   Expected callbackId was received
    2018-01-05 10:09:14.075 Detail,   Expected reply was received
    2018-01-05 10:09:14.075 Detail,   Message transaction complete
    2018-01-05 10:09:14.075 Detail,
    2018-01-05 10:09:14.075 Detail, Node028, Removing current message
    2018-01-05 10:09:14.075 Detail,
    2018-01-05 10:09:14.075 Info, Node028, Sending (Send) message (Callback ID=0x35, Expected Reply=0x04) - ThermostatSetpointCmd_Get (Node=28): 0x01, 0x0a, 0x00, 0x13, 0x1c, 0x03, 0x43, 0x02, 0x01, 0x25, 0x35, 0xa9
    2018-01-05 10:09:14.082 Detail, Node028,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
    2018-01-05 10:09:14.083 Detail, Node028,   ZW_SEND_DATA delivered to Z-Wave stack
    2018-01-05 10:09:14.100 Detail, Node028,   Received: 0x01, 0x07, 0x00, 0x13, 0x35, 0x00, 0x00, 0x02, 0xdc
    2018-01-05 10:09:14.100 Detail, Node028,   ZW_SEND_DATA Request with callback ID 0x35 received (expected 0x35)
    2018-01-05 10:09:14.100 Info, Node028, Request RTT 24 Average Request RTT 356
    2018-01-05 10:09:14.100 Detail,   Expected callbackId was received
    2018-01-05 10:09:14.138 Detail, Node028,   Received: 0x01, 0x0b, 0x00, 0x04, 0x00, 0x1c, 0x05, 0x43, 0x03, 0x01, 0x09, 0x42, 0xe3
    2018-01-05 10:09:14.138 Detail,
    2018-01-05 10:09:14.138 Info, Node028, Response RTT 62 Average Response RTT 65
    2018-01-05 10:09:14.138 Detail, Node028, Refreshed Value: old value=65, new value=66, type=decimal
    2018-01-05 10:09:14.138 Detail, Node028, Changes to this value are not verified
    2018-01-05 10:09:14.138 Info, Node028, Received thermostat setpoint report: Setpoint Heating 1 = 66F
    2018-01-05 10:09:14.138 Detail, Node028,   Expected reply and command class was received
    2018-01-05 10:09:14.138 Detail, Node028,   Message transaction complete
    2018-01-05 10:09:14.138 Detail,
    2018-01-05 10:09:14.138 Detail, Node028, Removing current message
    2018-01-05 10:09:14.138 Detail, Node028, Notification: ValueChanged

Please Advise.

2

I’m having a similar problem with my Trane XR524 thermostat. However, mine ends in an error:

2018-01-08 07:58:36.614 Detail, Node028, Notification: ValueChanged                                                                                                                                                                                                                                                                     
2018-01-08 09:07:47.805 Info, Node028, Value::Set - COMMAND_CLASS_THERMOSTAT_SETPOINT - Away Heating - 13 - 1 - 72                                                                                                                                                                                                                      
2018-01-08 09:07:47.812 Detail, Node028, Queuing (Send) ThermostatSetpointCmd_Set (Node=28): 0x01, 0x0c, 0x00, 0x13, 0x1c, 0x05, 0x43, 0x01, 0x0d, 0x01, 0x48, 0x25, 0xcb, 0x11                                                                                                                                                         
2018-01-08 09:07:47.812 Detail, Node028, Queuing (Send) ThermostatSetpointCmd_Get (Node=28): 0x01, 0x0a, 0x00, 0x13, 0x1c, 0x03, 0x43, 0x02, 0x0d, 0x25, 0xcc, 0x5c                                                                                                                                                                     
2018-01-08 09:07:47.812 Info, Node028, Sending (Send) message (Callback ID=0xcb, Expected Reply=0x13) - ThermostatSetpointCmd_Set (Node=28): 0x01, 0x0c, 0x00, 0x13, 0x1c, 0x05, 0x43, 0x01, 0x0d, 0x01, 0x48, 0x25, 0xcb, 0x11                                                                                                         
2018-01-08 09:07:47.821 Detail, Node028,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8                                                                                                                                                                                                                                                 
2018-01-08 09:07:47.822 Detail, Node028,   ZW_SEND_DATA delivered to Z-Wave stack                                                                                                                                                                                                                                                       
2018-01-08 09:07:47.869 Detail, Node028,   Received: 0x01, 0x07, 0x00, 0x13, 0xcb, 0x00, 0x00, 0x05, 0x25                                                                                                                                                                                                                               
2018-01-08 09:07:47.869 Detail, Node028,   ZW_SEND_DATA Request with callback ID 0xcb received (expected 0xcb)                                                                                                                                                                                                                          
2018-01-08 09:07:47.869 Info, Node028, Request RTT 56 Average Request RTT 60                                                                                                                                                                                                                                                            
2018-01-08 09:07:47.869 Detail, Node028, Removing current message                                                                                                                                                                                                                                                                       
2018-01-08 09:07:47.870 Info, Node028, Sending (Send) message (Callback ID=0xcc, Expected Reply=0x04) - ThermostatSetpointCmd_Get (Node=28): 0x01, 0x0a, 0x00, 0x13, 0x1c, 0x03, 0x43, 0x02, 0x0d, 0x25, 0xcc, 0x5c                                                                                                                     
2018-01-08 09:07:47.879 Detail, Node028,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8                                                                                                                                                                                                                                                 
2018-01-08 09:07:47.879 Detail, Node028,   ZW_SEND_DATA delivered to Z-Wave stack                                                                                                                                                                                                                                                       
2018-01-08 09:07:47.926 Detail, Node028,   Received: 0x01, 0x07, 0x00, 0x13, 0xcc, 0x00, 0x00, 0x06, 0x21                                                                                                                                                                                                                               
2018-01-08 09:07:47.926 Detail, Node028,   ZW_SEND_DATA Request with callback ID 0xcc received (expected 0xcc)                                                                                                                                                                                                                          
2018-01-08 09:07:47.926 Info, Node028, Request RTT 55 Average Request RTT 57                                                                                                                                                                                                                                                            
2018-01-08 09:07:57.869 Error, Node028, ERROR: Dropping command, expected response not received after 1 attempt(s)                                                                                                                                                                                                                      
2018-01-08 09:07:57.869 Detail, Node028, Removing current message                                                                                                                                                                                                                                                                       
2018-01-08 09:07:57.869 Detail, Node028, Notification: Notification - TimeOut

Like you, I see mode changes happen immediately.

There are numerous posts around the forums where people are having problems setting temperatures with the Climate component and Zwave thermostats. I think something is definitely broken but I’m not having much luck finding a fix.

Just curious, are you on Hassio? My specific thermostat seems to need to reference a trane XML file that was part of the manufacturer_specific.xml file from OpenZwave. This no longer seems to exist in Hassio.

3

It’s a little unclear just from the logs what is actually happening. The immediate “get” after the set may not reflect the new value yet. If you only send one, does it really not update on the device, or does it only not update in time for the immediate following get? Is the second one just picking up the updated value that was already set? Or does it really take two sets to change on the device?

There is a device_config flag “delay” which may help with this. Here’s an example using a dimmer, but it may be helpful for this, too.

device_config: 
    light.ge_12724_3way_dimmer_switch_level_8_0:
      refresh_value: true
      delay: 3
4

Yes i am running Hassio.

Add the refresh_value/delay didn’t help, for clarity:
climate.thermostat_heating_1:
ignored: false
refresh_value: true
delay: 3

The change does NOT eventually get reflected in the thermostat. If I manually call the service numerous times then it will eventually get reflected.