Updates to thermostat revert to previous value within milliseconds

Hello,

I noticed some updates to the cool set point of my CT 100, were applied and then reverted back to the original value. This was especially the case for updates triggered through rules. I just updated to the latest snapshot (openHAB 2.4.0 Build #1364, followed instructions here:ZWave binding updates) in an attempt to remedy this, but now all updates are being immediately reverted to their previous values.

Any ideas would be greatly appreciated.

2018-09-16 13:21:53.206 [ome.event.ItemCommandEvent] - Item 'HVAC_CoolSetPoint' received command 78

2018-09-16 13:21:53.222 [nt.ItemStatePredictedEvent] - HVAC_CoolSetPoint predicted to become 78

2018-09-16 13:21:53.238 [vent.ItemStateChangedEvent] - HVAC_CoolSetPoint changed from 77 to 78

==> /var/log/openhab2/openhab.log <==

2018-09-16 13:21:53.250 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Command received zwave:device:39a25486:node6:thermostat_setpoint_cooling --> 78 °C

2018-09-16 13:21:53.259 [DEBUG] [ter.ZWaveThermostatSetpointConverter] - NODE 6: Thermostat command received for 78 °C

2018-09-16 13:21:53.278 [DEBUG] [.ZWaveThermostatSetpointCommandClass] - NODE 6: Creating new message for command THERMOSTAT_SETPOINT_SET

2018-09-16 13:21:53.284 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 6: SECURITY not supported

2018-09-16 13:21:53.291 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 6: Command Class COMMAND_CLASS_THERMOSTAT_SETPOINT is NOT required to be secured

2018-09-16 13:21:53.304 [DEBUG] [ter.ZWaveThermostatSetpointConverter] - NODE 6: Sending Message: org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@ed3a47

2018-09-16 13:21:53.309 [DEBUG] [.ZWaveThermostatSetpointCommandClass] - NODE 6: Creating new message for application command THERMOSTAT_SETPOINT_GET (Cooling)

2018-09-16 13:21:53.314 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 6: SECURITY not supported

2018-09-16 13:21:53.318 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 6: Command Class COMMAND_CLASS_THERMOSTAT_SETPOINT is NOT required to be secured

2018-09-16 13:21:53.322 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 6: Adding to device queue

2018-09-16 13:21:53.326 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2018-09-16 13:21:53.334 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0C 00 13 06 05 43 01 02 01 4E 25 DB 12 

2018-09-16 13:21:53.340 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 6: Sending REQUEST Message = 01 0C 00 13 06 05 43 01 02 01 4E 25 DB 12 

2018-09-16 13:21:53.345 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT

2018-09-16 13:21:53.348 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06

2018-09-16 13:21:53.349 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 475: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 219

2018-09-16 13:21:53.354 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=

2018-09-16 13:21:53.358 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 6: Adding to device queue

2018-09-16 13:21:53.359 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=

2018-09-16 13:21:53.364 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2018-09-16 13:21:53.364 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 475: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 219

2018-09-16 13:21:53.370 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK

2018-09-16 13:21:53.373 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2018-09-16 13:21:53.375 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2018-09-16 13:21:53.370 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Polling intialised at 1800 seconds - start in 1500 milliseconds.

2018-09-16 13:21:53.383 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 

2018-09-16 13:21:53.388 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 

2018-09-16 13:21:53.392 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 

2018-09-16 13:21:53.397 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 475: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 219

2018-09-16 13:21:53.401 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 DB 00 00 05 35 

2018-09-16 13:21:53.401 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1

2018-09-16 13:21:53.406 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 475: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 219

2018-09-16 13:21:53.407 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=219, payload=DB 00 00 05 

2018-09-16 13:21:53.418 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 

2018-09-16 13:21:53.423 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 6: sentData successfully placed on stack.

2018-09-16 13:21:53.427 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 475: Advanced to WAIT_REQUEST

2018-09-16 13:21:53.430 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 6: TID 475: Transaction not completed

2018-09-16 13:21:53.433 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=219, payload=DB 00 00 05 

2018-09-16 13:21:53.435 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 475: [WAIT_REQUEST] priority=Set, requiresResponse=true, callback: 219

2018-09-16 13:21:53.438 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1

2018-09-16 13:21:53.440 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 475: [WAIT_REQUEST] priority=Set, requiresResponse=true, callback: 219

2018-09-16 13:21:53.442 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 475: (Callback 219)

2018-09-16 13:21:53.446 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!

2018-09-16 13:21:53.449 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 475: callback 219

2018-09-16 13:21:53.453 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=219, payload=DB 00 00 05 

2018-09-16 13:21:53.456 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 6: SendData Request. CallBack ID = 219, Status = Transmission complete and ACK received(0)

2018-09-16 13:21:53.461 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 6: resetResendCount initComplete=true isDead=false

2018-09-16 13:21:53.463 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 475: Transaction COMPLETED

2018-09-16 13:21:53.466 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 6: Response processed after 117ms

2018-09-16 13:21:53.468 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 6: TID 475: Transaction completed

2018-09-16 13:21:53.470 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 6: notifyTransactionResponse TID:475 DONE

2018-09-16 13:21:53.473 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent

2018-09-16 13:21:53.475 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2018-09-16 13:21:53.478 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2018-09-16 13:21:53.482 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 06 03 43 02 02 25 DC 59 

2018-09-16 13:21:53.487 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 6: Sending REQUEST Message = 01 0A 00 13 06 03 43 02 02 25 DC 59 

2018-09-16 13:21:53.490 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT

2018-09-16 13:21:53.493 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06

2018-09-16 13:21:53.494 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 476: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 220

2018-09-16 13:21:53.496 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=

2018-09-16 13:21:53.499 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=

2018-09-16 13:21:53.501 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 

2018-09-16 13:21:53.503 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 476: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 220

2018-09-16 13:21:53.505 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 

2018-09-16 13:21:53.507 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK

2018-09-16 13:21:53.511 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 

2018-09-16 13:21:53.516 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 476: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 220

2018-09-16 13:21:53.519 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1

2018-09-16 13:21:53.523 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 476: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 220

2018-09-16 13:21:53.527 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 

2018-09-16 13:21:53.531 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 6: sentData successfully placed on stack.

2018-09-16 13:21:53.535 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 476: Advanced to WAIT_REQUEST

2018-09-16 13:21:53.538 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 6: TID 476: Transaction not completed

2018-09-16 13:21:53.541 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2018-09-16 13:21:53.545 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2018-09-16 13:21:53.545 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 DC 00 00 05 32 

2018-09-16 13:21:53.553 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=220, payload=DC 00 00 05 

2018-09-16 13:21:53.556 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=220, payload=DC 00 00 05 

2018-09-16 13:21:53.559 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 476: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 220

2018-09-16 13:21:53.561 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1

2018-09-16 13:21:53.564 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 476: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 220

2018-09-16 13:21:53.566 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 476: (Callback 220)

2018-09-16 13:21:53.569 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!

2018-09-16 13:21:53.571 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 476: callback 220

2018-09-16 13:21:53.576 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=220, payload=DC 00 00 05 

2018-09-16 13:21:53.578 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 6: SendData Request. CallBack ID = 220, Status = Transmission complete and ACK received(0)

2018-09-16 13:21:53.581 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 6: resetResendCount initComplete=true isDead=false

2018-09-16 13:21:53.584 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 476: Advanced to WAIT_DATA

2018-09-16 13:21:53.587 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 6: TID 476: Transaction not completed

2018-09-16 13:21:53.590 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2018-09-16 13:21:53.594 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2018-09-16 13:21:53.795 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0B 00 04 00 06 05 43 03 02 09 4D F5 

2018-09-16 13:21:53.804 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=6, callback=0, payload=00 06 05 43 03 02 09 4D 

2018-09-16 13:21:53.810 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=6, callback=0, payload=00 06 05 43 03 02 09 4D 

2018-09-16 13:21:53.813 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null

2018-09-16 13:21:53.820 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 6: Application Command Request (ALIVE:DONE)

2018-09-16 13:21:53.824 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 6: resetResendCount initComplete=true isDead=false

2018-09-16 13:21:53.829 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 6: Incoming command class COMMAND_CLASS_THERMOSTAT_SETPOINT, endpoint 0

2018-09-16 13:21:53.832 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 6: SECURITY not supported

2018-09-16 13:21:53.837 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 6: Received COMMAND_CLASS_THERMOSTAT_SETPOINT V1 THERMOSTAT_SETPOINT_REPORT

2018-09-16 13:21:53.841 [DEBUG] [.ZWaveThermostatSetpointCommandClass] - NODE 6: Thermostat Setpoint report Scale = 1

2018-09-16 13:21:53.847 [DEBUG] [.ZWaveThermostatSetpointCommandClass] - NODE 6: Thermostat Setpoint Value = 77

2018-09-16 13:21:53.850 [DEBUG] [.ZWaveThermostatSetpointCommandClass] - NODE 6: Thermostat Setpoint Report, Type Cooling (2), value = 77

2018-09-16 13:21:53.856 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Got an event from Z-Wave network: ZWaveThermostatSetpointValueEvent

2018-09-16 13:21:53.859 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Got a value event from Z-Wave network, endpoint = 0, command class = COMMAND_CLASS_THERMOSTAT_SETPOINT, value = 77

2018-09-16 13:21:53.865 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Updating channel state zwave:device:39a25486:node6:thermostat_setpoint_cooling to 77 °F [QuantityType]

2018-09-16 13:21:53.873 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 6: Commands processed 1.

==> /var/log/openhab2/events.log <==

2018-09-16 13:21:53.883 [vent.ItemStateChangedEvent] - HVAC_CoolSetPoint changed from 78 to 77s

Probably you missed the part about setting the locale? Either that, or you like your heating REALLY hot as you’re setting it to 78 deg C.

Thanks for the quick reply! I managed to get it to work by adding the unit in the Item file.

You can set set the default in the system settings -:

The binding will now send through the units to the device, so this needs to be set correctly…

Seems I was celebrating to early. There were at least two different problems. Setting the locale fixed issue one: changing the value manually through habpanel etc. However issue two changing the value from rules still persists.

logfile

There’s nothing wrong with what the binding is sending -:

Does the thermostat actually change temperature?

When I trigger the update this way (through a rule) my dummy in habpanel blinks the new value, then goes back, the thermostat lcd doesn’t change at all. When changed out off habpanel, the update goes through and is reflected on the thermostat. When changed on the thermostat the new value is correctly updated in openhab.

In that case you need to work out what the difference is - check the logs for both and there must be a difference.

The difference seems to be that the rule sends a command to change the opmode to cool and sets a cool setpoint at basically the same time. While changing the value through habpanel only updates the set point. I commented the part with the opmode change out off the rule and now the setpoint is being updated as expected.
No idea why it doesn’t like both changes at once (especially as it has worked intermittent in the past), but I should be able to find a way around that now.

Thanks for pointing me in the right direction again!

I am having this problem with my CT30 - It was working with no issues. I upgraded my ubuntu server from 14.04 to 16.04 and that broke all of my zwave devices. I have since got them all working again except now my setpoints are changing the value and they immediately change back (to 78F in my case). I have looked at the latest binding documentation and believe I am using the correct syntax.

Number HVAC_CoolSetPoint "Cool Set [%.1f F]" <thermostat> (HVAC) {zwave="5:command=thermostat_setpoint,setpoint_type=2,setpoint_scale=1" }


I am also seeing in the event log

2018-09-25 11:25:15.853 [ome.event.ItemCommandEvent] - Item 'HVAC_CoolSetPoint' received command 80
2018-09-25 11:25:15.859 [nt.ItemStatePredictedEvent] - HVAC_CoolSetPoint predicted to become 80
2018-09-25 11:25:15.864 [vent.ItemStateChangedEvent] - HVAC_CoolSetPoint changed from 78 to 80
2018-09-25 11:25:26.785 [vent.ItemStateChangedEvent] - HVAC_CoolSetPoint changed from 80 to 78

I can change the fan mode and the heating mode but I can’t change any setpoints. I am not sure what the difference is. I have checked through habmin to make sure that all the items are associated correctly. I don’t see any errors showing in habmin for the device.

I have set my default units in PaperUI to Imperial. I am not sure what else I can try, @chris any guidance on what else to check would be greatly appreciated.

I just wanted to add, I have installed the latest binding and removed the thing and added it again. The symptoms are the same.

This is my XML for the node

<node>
  <homeId>0x1852b21</homeId>
  <nodeId>5</nodeId>
  <version>3</version>
  <manufacturer>0x98</manufacturer>
  <deviceId>0x0</deviceId>
  <deviceType>0x0</deviceType>
  <listening>true</listening>
  <frequentlyListening>false</frequentlyListening>
  <routing>true</routing>
  <security>false</security>
  <beaming>true</beaming>
  <maxBaudRate>40000</maxBaudRate>
  <sleepDelay>1000</sleepDelay>
  <nodeInformationFrame>
    <commandClass>COMMAND_CLASS_BASIC</commandClass>
    <commandClass>COMMAND_CLASS_CLOCK</commandClass>
    <commandClass>COMMAND_CLASS_INDICATOR</commandClass>
    <commandClass>COMMAND_CLASS_MANUFACTURER_SPECIFIC</commandClass>
    <commandClass>COMMAND_CLASS_SENSOR_MULTILEVEL</commandClass>
    <commandClass>COMMAND_CLASS_THERMOSTAT_MODE</commandClass>
    <commandClass>COMMAND_CLASS_THERMOSTAT_OPERATING_STATE</commandClass>
    <commandClass>COMMAND_CLASS_THERMOSTAT_FAN_MODE</commandClass>
    <commandClass>COMMAND_CLASS_THERMOSTAT_FAN_STATE</commandClass>
    <commandClass>COMMAND_CLASS_THERMOSTAT_SETPOINT</commandClass>
    <commandClass>COMMAND_CLASS_VERSION</commandClass>
    <commandClass>COMMAND_CLASS_CONFIGURATION</commandClass>
    <commandClass>COMMAND_CLASS_BATTERY</commandClass>
    <commandClass>COMMAND_CLASS_ASSOCIATION</commandClass>
  </nodeInformationFrame>
  <associationGroups class="concurrent-hash-map">
    <entry>
      <int>1</int>
      <associationGroup>
        <index>1</index>
        <maxNodes>0</maxNodes>
        <associations>
          <associationMember>
            <node>1</node>
          </associationMember>
        </associations>
      </associationGroup>
    </entry>
  </associationGroups>
  <endpoints class="concurrent-hash-map">
    <entry>
      <int>0</int>
      <endPoint>
        <deviceClass>
          <basicDeviceClass>BASIC_TYPE_ROUTING_SLAVE</basicDeviceClass>
          <genericDeviceClass>GENERIC_TYPE_THERMOSTAT</genericDeviceClass>
          <specificDeviceClass>SPECIFIC_TYPE_THERMOSTAT_GENERAL_V2</specificDeviceClass>
        </deviceClass>
        <endpointId>0</endpointId>
        <secureCommandClasses/>
        <supportedCommandClasses class="concurrent-hash-map">
          <entry>
            <commandClass>COMMAND_CLASS_MANUFACTURER_SPECIFIC</commandClass>
            <COMMAND__CLASS__MANUFACTURER__SPECIFIC>
              <version>1</version>
              <instances>1</instances>
              <control>false</control>
              <versionSupported>1</versionSupported>
              <initSerialNumber>false</initSerialNumber>
              <deviceManufacturer>152</deviceManufacturer>
              <deviceType>0</deviceType>
              <deviceId>0</deviceId>
            </COMMAND__CLASS__MANUFACTURER__SPECIFIC>
          </entry>
          <entry>
            <commandClass>COMMAND_CLASS_BASIC</commandClass>
            <COMMAND__CLASS__BASIC>
              <version>1</version>
              <instances>1</instances>
              <control>false</control>
              <versionSupported>1</versionSupported>
              <isGetSupported>true</isGetSupported>
            </COMMAND__CLASS__BASIC>
          </entry>
          <entry>
            <commandClass>COMMAND_CLASS_NO_OPERATION</commandClass>
            <COMMAND__CLASS__NO__OPERATION>
              <version>1</version>
              <instances>1</instances>
              <control>false</control>
              <versionSupported>1</versionSupported>
            </COMMAND__CLASS__NO__OPERATION>
          </entry>
          <entry>
            <commandClass>COMMAND_CLASS_CONFIGURATION</commandClass>
            <COMMAND__CLASS__CONFIGURATION>
              <version>1</version>
              <instances>1</instances>
              <control>false</control>
              <versionSupported>1</versionSupported>
              <configParameters/>
            </COMMAND__CLASS__CONFIGURATION>
          </entry>
          <entry>
            <commandClass>COMMAND_CLASS_THERMOSTAT_OPERATING_STATE</commandClass>
            <COMMAND__CLASS__THERMOSTAT__OPERATING__STATE>
              <version>1</version>
              <instances>1</instances>
              <control>false</control>
              <versionSupported>2</versionSupported>
              <isGetSupported>true</isGetSupported>
            </COMMAND__CLASS__THERMOSTAT__OPERATING__STATE>
          </entry>
          <entry>
            <commandClass>COMMAND_CLASS_ASSOCIATION</commandClass>
            <COMMAND__CLASS__ASSOCIATION>
              <version>1</version>
              <instances>1</instances>
              <control>false</control>
              <versionSupported>1</versionSupported>
              <maxGroups>1</maxGroups>
            </COMMAND__CLASS__ASSOCIATION>
          </entry>
          <entry>
            <commandClass>COMMAND_CLASS_THERMOSTAT_FAN_MODE</commandClass>
            <COMMAND__CLASS__THERMOSTAT__FAN__MODE>
              <version>1</version>
              <instances>1</instances>
              <control>false</control>
              <versionSupported>1</versionSupported>
              <fanModeTypes>
                <fanModeType>ON_LOW</fanModeType>
                <fanModeType>AUTO_LOW</fanModeType>
              </fanModeTypes>
              <isGetSupported>true</isGetSupported>
            </COMMAND__CLASS__THERMOSTAT__FAN__MODE>
          </entry>
          <entry>
            <commandClass>COMMAND_CLASS_THERMOSTAT_FAN_STATE</commandClass>
            <COMMAND__CLASS__THERMOSTAT__FAN__STATE>
              <version>1</version>
              <instances>1</instances>
              <control>false</control>
              <versionSupported>1</versionSupported>
              <fanStateTypes/>
              <isGetSupported>true</isGetSupported>
            </COMMAND__CLASS__THERMOSTAT__FAN__STATE>
          </entry>
          <entry>
            <commandClass>COMMAND_CLASS_SENSOR_MULTILEVEL</commandClass>
            <COMMAND__CLASS__SENSOR__MULTILEVEL>
              <version>2</version>
              <instances>1</instances>
              <control>false</control>
              <versionSupported>2</versionSupported>
              <sensors>
                <entry>
                  <multilevelSensorType>TEMPERATURE</multilevelSensorType>
                  <multilevelSensor>
                    <sensorType>TEMPERATURE</sensorType>
                    <initialised>true</initialised>
                  </multilevelSensor>
                </entry>
              </sensors>
              <isGetSupported>true</isGetSupported>
            </COMMAND__CLASS__SENSOR__MULTILEVEL>
          </entry>
          <entry>
            <commandClass>COMMAND_CLASS_BATTERY</commandClass>
            <COMMAND__CLASS__BATTERY>
              <version>1</version>
              <instances>1</instances>
              <control>false</control>
              <versionSupported>1</versionSupported>
              <batteryLevel>100</batteryLevel>
              <batteryLow>false</batteryLow>
              <isGetSupported>true</isGetSupported>
            </COMMAND__CLASS__BATTERY>
          </entry>
          <entry>
            <commandClass>COMMAND_CLASS_CLOCK</commandClass>
            <COMMAND__CLASS__CLOCK>
              <version>1</version>
              <instances>1</instances>
              <control>false</control>
              <versionSupported>1</versionSupported>
            </COMMAND__CLASS__CLOCK>
          </entry>
          <entry>
            <commandClass>COMMAND_CLASS_INDICATOR</commandClass>
            <COMMAND__CLASS__INDICATOR>
              <version>1</version>
              <instances>1</instances>
              <control>false</control>
              <versionSupported>1</versionSupported>
              <isGetSupported>true</isGetSupported>
              <supportedIndicatorsInitialised>true</supportedIndicatorsInitialised>
              <supportedIndicators/>
            </COMMAND__CLASS__INDICATOR>
          </entry>
          <entry>
            <commandClass>COMMAND_CLASS_VERSION</commandClass>
            <COMMAND__CLASS__VERSION>
              <version>1</version>
              <instances>1</instances>
              <control>false</control>
              <versionSupported>1</versionSupported>
              <libraryType>LIB_SLAVE_ENHANCED</libraryType>
              <protocolVersion>3.28</protocolVersion>
              <applicationVersion>8.7</applicationVersion>
            </COMMAND__CLASS__VERSION>
          </entry>
          <entry>
            <commandClass>COMMAND_CLASS_THERMOSTAT_MODE</commandClass>
            <COMMAND__CLASS__THERMOSTAT__MODE>
              <version>1</version>
              <instances>1</instances>
              <control>false</control>
              <versionSupported>2</versionSupported>
              <modeTypes>
                <modeType>HEAT</modeType>
                <modeType>COOL</modeType>
                <modeType>OFF</modeType>
              </modeTypes>
              <isGetSupported>true</isGetSupported>
            </COMMAND__CLASS__THERMOSTAT__MODE>
          </entry>
          <entry>
            <commandClass>COMMAND_CLASS_THERMOSTAT_SETPOINT</commandClass>
            <COMMAND__CLASS__THERMOSTAT__SETPOINT>
              <version>1</version>
              <instances>1</instances>
              <control>false</control>
              <versionSupported>2</versionSupported>
              <setpoints>
                <entry>
                  <setpointType>COOLING</setpointType>
                  <setpoint>
                    <setpointType>COOLING</setpointType>
                    <initialised>true</initialised>
                    <initCount>0</initCount>
                    <outer-class reference="../../../.."/>
                  </setpoint>
                </entry>
                <entry>
                  <setpointType>HEATING</setpointType>
                  <setpoint>
                    <setpointType>HEATING</setpointType>
                    <initialised>true</initialised>
                    <initCount>0</initCount>
                    <outer-class reference="../../../.."/>
                  </setpoint>
                </entry>
              </setpoints>
              <isGetSupported>true</isGetSupported>
            </COMMAND__CLASS__THERMOSTAT__SETPOINT>
          </entry>
        </supportedCommandClasses>
      </endPoint>
    </entry>
  </endpoints>
  <nodeNeighbors>
    <int>4</int>
    <int>6</int>
    <int>7</int>
  </nodeNeighbors>
  <lastReceived>2018-09-25 17:44:36.144 UTC</lastReceived>
</node>

I also put the Zwave binding in debug mode and captured the log, I viewed in the log viewer but not really sure what I am looking at.

17:20:53.911	5	
TX REQ SendData 2 Zero length frame in command class  ACK AUTO_ROUTE
17:20:53.933	5	
RX RES SendData 2 ACCEPTED BY CONTROLLER 0 /128
17:20:54.268	5	
RX REQ ApplicationCommandHandler SENSOR_MULTI_LEVEL_REPORT TEMPERATURE=42 0 /128
17:20:54.314	5	
STATE UPDATE zwave:device:0001:node5 8-09-25 17:20:54.314 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Updating channel state zwave:device:0001:node5:
17:20:54.351	5	
TX REQ SendData 2 Zero length frame in command class  ACK AUTO_ROUTE
17:20:54.399	5	
RX RES SendData 2 ACCEPTED BY CONTROLLER 0 /128
17:20:59.502	5	
TX REQ SendData 3 Zero length frame in command class  ACK AUTO_ROUTE
17:20:59.509	5	
RX RES SendData 3 ACCEPTED BY CONTROLLER 0 /128
17:20:59.941	5	
RX REQ ApplicationCommandHandler THERMOSTAT_SETPOINT_REPORT TYPE=2 SCALE=1 0 /128
17:20:59.972	5	
STATE UPDATE zwave:device:0001:node5 8-09-25 17:20:59.972 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Updating channel state zwave:device:0001:node5:
17:21:00.004	5	
TX REQ SendData 3 Zero length frame in command class  ACK AUTO_ROUTE
17:21:00.016	5	
RX RES SendData 3 ACCEPTED BY CONTROLLER 1 /128
17:21:00.299	5	
RX REQ ApplicationCommandHandler THERMOSTAT_SETPOINT_REPORT TYPE=1 SCALE=1 0 /128
17:21:00.323	5	
STATE UPDATE zwave:device:0001:node5 8-09-25 17:21:00.323 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Updating channel state zwave:device:0001:node5:
17:21:00.344	5	
TX REQ SendData 2 Zero length frame in command class  ACK AUTO_ROUTE
17:21:00.351	5	
RX RES SendData 2 ACCEPTED BY CONTROLLER 0 /128
17:21:00.688	5	
RX REQ ApplicationCommandHandler THERMOSTAT_FAN_MODE_REPORT 0 /128
17:21:00.700	5	
STATE UPDATE zwave:device:0001:node5 8-09-25 17:21:00.700 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Updating channel state zwave:device:0001:node5:
17:21:00.715	5	
TX REQ SendData 2 Zero length frame in command class  ACK AUTO_ROUTE
17:21:00.721	5	
RX RES SendData 2 ACCEPTED BY CONTROLLER 0 /128

I don’t know if the zero length frame in command class messages are a problem or not.

The pretty version:

I have exhausted all the documentation I have found, nothing seems to point me to a solution for this. It used to work perfectly and now I only have control of the fan and the modes. Obviously the set points are the critical aspect with a thermostat.

Please can you provide the raw log - the log above is, well, I don’t really know what it is other than it’s been heavily filtered and modified :wink: . The pretty version is useful, but I need the real log so I can process it myself and find out what is happening.

etedEvent
2018-09-28 13:32:02.318 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2018-09-28 13:32:02.318 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2018-09-28 13:32:02.318 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2018-09-28 13:32:02.318 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2018-09-28 13:32:02.319 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 05 02 44 02 25 13 92
2018-09-28 13:32:02.319 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 5: Sending REQUEST Message = 01 09 00 13 05 02 44 02 25 13 92
2018-09-28 13:32:02.320 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2018-09-28 13:32:02.321 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 568: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 19
2018-09-28 13:32:02.322 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2018-09-28 13:32:02.323 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2018-09-28 13:32:02.323 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2018-09-28 13:32:02.324 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 568: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 19
2018-09-28 13:32:02.324 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2018-09-28 13:32:02.324 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2018-09-28 13:32:02.324 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2018-09-28 13:32:02.325 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2018-09-28 13:32:02.327 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2018-09-28 13:32:02.328 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2018-09-28 13:32:02.328 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 568: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 19
2018-09-28 13:32:02.328 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2018-09-28 13:32:02.329 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 568: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 19
2018-09-28 13:32:02.329 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2018-09-28 13:32:02.329 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 5: sentData successfully placed on stack.
2018-09-28 13:32:02.330 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 568: Advanced to WAIT_REQUEST
2018-09-28 13:32:02.330 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: TID 568: Transaction not completed
2018-09-28 13:32:02.330 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2018-09-28 13:32:02.330 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2018-09-28 13:32:02.417 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 00 13 13 00 FA
2018-09-28 13:32:02.418 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=19, payload=13 00
2018-09-28 13:32:02.419 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=19, payload=13 00
2018-09-28 13:32:02.419 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 568: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 19
2018-09-28 13:32:02.420 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2018-09-28 13:32:02.420 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 568: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 19
2018-09-28 13:32:02.420 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 568: (Callback 19)
2018-09-28 13:32:02.420 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2018-09-28 13:32:02.421 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 568: callback 19
2018-09-28 13:32:02.421 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=19, payload=13 00
2018-09-28 13:32:02.421 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 5: SendData Request. CallBack ID = 19, Status = Transmission complete and ACK received(0)
2018-09-28 13:32:02.422 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: resetResendCount initComplete=true isDead=false
2018-09-28 13:32:02.422 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 568: Advanced to WAIT_DATA
2018-09-28 13:32:02.422 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: TID 568: Transaction not completed
2018-09-28 13:32:02.423 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2018-09-28 13:32:02.423 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2018-09-28 13:32:02.726 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 05 03 44 03 00 B3
2018-09-28 13:32:02.727 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 03 44 03 00
2018-09-28 13:32:02.728 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 03 44 03 00
2018-09-28 13:32:02.728 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2018-09-28 13:32:02.729 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Application Command Request (ALIVE:DONE)
2018-09-28 13:32:02.729 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: resetResendCount initComplete=true isDead=false
2018-09-28 13:32:02.729 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: Incoming command class COMMAND_CLASS_THERMOSTAT_FAN_MODE, endpoint 0
2018-09-28 13:32:02.729 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: SECURITY not supported
2018-09-28 13:32:02.730 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 5: Received COMMAND_CLASS_THERMOSTAT_FAN_MODE V1 THERMOSTAT_FAN_MODE_REPORT
2018-09-28 13:32:02.730 [DEBUG] [s.ZWaveThermostatFanModeCommandClass] - NODE 5: Thermostat Fan Mode report value = 0
2018-09-28 13:32:02.730 [DEBUG] [s.ZWaveThermostatFanModeCommandClass] - NODE 5: Thermostat Fan Mode Report value = Auto Low
2018-09-28 13:32:02.731 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2018-09-28 13:32:02.731 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got a value event from Z-Wave network, endpoint = 0, command class = COMMAND_CLASS_THERMOSTAT_FAN_MODE, value = 0
2018-09-28 13:32:02.732 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Updating channel state zwave:device:0001:node5:thermostat_fanmode to 0 [DecimalType]
2018-09-28 13:32:02.733 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Commands processed 1.
2018-09-28 13:32:02.734 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@39a6d725.
2018-09-28 13:32:02.734 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Command verified org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@39a6d725.
2018-09-28 13:32:02.734 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: notifyTransactionResponse TID:568 DONE
2018-09-28 13:32:02.736 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2018-09-28 13:32:02.736 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2018-09-28 13:32:02.736 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2018-09-28 13:32:02.737 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2018-09-28 13:32:02.737 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2018-09-28 13:32:02.737 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 05 02 80 02 25 14 51
2018-09-28 13:32:02.738 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 5: Sending REQUEST Message = 01 09 00 13 05 02 80 02 25 14 51
2018-09-28 13:32:02.744 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2018-09-28 13:32:02.746 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2018-09-28 13:32:02.746 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2018-09-28 13:32:02.747 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2018-09-28 13:32:02.748 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 569: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 20
2018-09-28 13:32:02.749 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2018-09-28 13:32:02.750 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 569: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 20
2018-09-28 13:32:02.751 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2018-09-28 13:32:02.755 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2018-09-28 13:32:02.756 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2018-09-28 13:32:02.757 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2018-09-28 13:32:02.757 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2018-09-28 13:32:02.758 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 569: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 20
2018-09-28 13:32:02.758 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2018-09-28 13:32:02.758 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 569: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 20
2018-09-28 13:32:02.758 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2018-09-28 13:32:02.759 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 5: sentData successfully placed on stack.
2018-09-28 13:32:02.759 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 569: Advanced to WAIT_REQUEST
2018-09-28 13:32:02.759 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: TID 569: Transaction not completed
2018-09-28 13:32:02.759 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2018-09-28 13:32:02.759 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2018-09-28 13:32:02.836 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 00 13 14 00 FD
2018-09-28 13:32:02.837 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=20, payload=14 00
2018-09-28 13:32:02.837 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=20, payload=14 00
2018-09-28 13:32:02.838 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 569: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 20
2018-09-28 13:32:02.838 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2018-09-28 13:32:02.839 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 569: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 20
2018-09-28 13:32:02.839 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 569: (Callback 20)
2018-09-28 13:32:02.839 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2018-09-28 13:32:02.839 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 569: callback 20
2018-09-28 13:32:02.840 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=20, payload=14 00
2018-09-28 13:32:02.840 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 5: SendData Request. CallBack ID = 20, Status = Transmission complete and ACK received(0)
2018-09-28 13:32:02.841 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: resetResendCount initComplete=true isDead=false
2018-09-28 13:32:02.841 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 569: Advanced to WAIT_DATA
2018-09-28 13:32:02.841 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: TID 569: Transaction not completed
2018-09-28 13:32:02.841 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2018-09-28 13:32:02.841 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2018-09-28 13:32:03.132 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 05 03 80 03 64 13
2018-09-28 13:32:03.134 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 03 80 03 64
2018-09-28 13:32:03.135 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 03 80 03 64
2018-09-28 13:32:03.136 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2018-09-28 13:32:03.137 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Application Command Request (ALIVE:DONE)
2018-09-28 13:32:03.137 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: resetResendCount initComplete=true isDead=false
2018-09-28 13:32:03.138 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: Incoming command class COMMAND_CLASS_BATTERY, endpoint 0
2018-09-28 13:32:03.139 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: SECURITY not supported
2018-09-28 13:32:03.140 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 5: Received COMMAND_CLASS_BATTERY V1 BATTERY_REPORT
2018-09-28 13:32:03.140 [DEBUG] [ommandclass.ZWaveBatteryCommandClass] - NODE 5: Battery report value = 100
2018-09-28 13:32:03.141 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2018-09-28 13:32:03.142 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got a value event from Z-Wave network, endpoint = 0, command class = COMMAND_CLASS_BATTERY, value = 100
2018-09-28 13:32:03.143 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Updating channel state zwave:device:0001:node5:battery-level to 100 [DecimalType]
2018-09-28 13:32:03.146 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Commands processed 1.
2018-09-28 13:32:03.147 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@156d34b6.
2018-09-28 13:32:03.148 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Command verified org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@156d34b6.
2018-09-28 13:32:03.149 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: notifyTransactionResponse TID:569 DONE
2018-09-28 13:32:03.149 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2018-09-28 13:32:03.150 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2018-09-28 13:32:03.150 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2018-09-28 13:32:03.150 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2018-09-28 13:32:03.151 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2018-09-28 13:32:03.151 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0C 00 13 05 05 43 01 01 01 45 25 15 D7
2018-09-28 13:32:03.151 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 5: Sending REQUEST Message = 01 0C 00 13 05 05 43 01 01 01 45 25 15 D7
2018-09-28 13:32:03.154 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2018-09-28 13:32:03.156 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2018-09-28 13:32:03.157 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2018-09-28 13:32:03.158 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2018-09-28 13:32:03.158 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 540: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 21
2018-09-28 13:32:03.159 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2018-09-28 13:32:03.159 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2018-09-28 13:32:03.168 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 540: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 21
2018-09-28 13:32:03.168 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2018-09-28 13:32:03.169 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2018-09-28 13:32:03.169 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 540: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 21
2018-09-28 13:32:03.170 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2018-09-28 13:32:03.170 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 540: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 21
2018-09-28 13:32:03.171 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2018-09-28 13:32:03.172 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 5: sentData successfully placed on stack.
2018-09-28 13:32:03.173 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 540: Advanced to WAIT_REQUEST
2018-09-28 13:32:03.173 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: TID 540: Transaction not completed
2018-09-28 13:32:03.174 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2018-09-28 13:32:03.174 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2018-09-28 13:32:03.244 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 00 13 15 00 FC
2018-09-28 13:32:03.246 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=21, payload=15 00
2018-09-28 13:32:03.246 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=21, payload=15 00
2018-09-28 13:32:03.247 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 540: [WAIT_REQUEST] priority=Set, requiresResponse=true, callback: 21
2018-09-28 13:32:03.247 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2018-09-28 13:32:03.248 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 540: [WAIT_REQUEST] priority=Set, requiresResponse=true, callback: 21
2018-09-28 13:32:03.248 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 540: (Callback 21)
2018-09-28 13:32:03.248 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2018-09-28 13:32:03.249 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 540: callback 21
2018-09-28 13:32:03.249 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=21, payload=15 00
2018-09-28 13:32:03.249 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 5: SendData Request. CallBack ID = 21, Status = Transmission complete and ACK received(0)
2018-09-28 13:32:03.250 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: resetResendCount initComplete=true isDead=false
2018-09-28 13:32:03.250 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 540: Transaction COMPLETED
2018-09-28 13:32:03.250 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Response processed after 92ms
2018-09-28 13:32:03.251 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: TID 540: Transaction completed
2018-09-28 13:32:03.251 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: notifyTransactionResponse TID:540 DONE
2018-09-28 13:32:03.255 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2018-09-28 13:32:03.255 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2018-09-28 13:32:03.256 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

Is this enough of it to work with? - I just changed the cool setpoint and the heat setpoint.

Did you get the right part of the log? I don’t see any setpoint commands in this log…

I was interested in the log you posted above which has all sorts of strange stuff in it - 0 length frames, and other strange corruption. Is this real, or is it an artefact of some processing you did to the log before viewing it?

The one above was before I turned on the debug mode. It is a real log of what was happening. Is there somewhere I can upload the whole file, I can give you the entire log rather than pasting it in. - I have it in debug mode for the zwave binding at the moment.

It’s very strange - it clearly has debug enabled, or there would be nothing showing, but it looks corrupted as there are lines extending into places that should never happen.

Anyway, if this is real, then I’d like to see this as something is very wrong :confused:.

There are many places on the net - you just need to find one (eg dropbox, github, icloud…).

– Link removed –

My guess is that problem is the commands are not formatted correctly…

Normally, there is a degree symbol in the command - like you see in the state update below -:

However, in your commands, it’s different -:

The binding is not getting the unit from this, so it is using degC, and this is likely then being rejected by the thermostat.

1 Like

Maybe the first one looked strange because I had copy pasted into a file on my Mac, not sure but I can tell you that I certainly didn’t make it up. - That’s what I see in my logs. I don’t think it was in DEBUG mode or each line would have had [DEBUG] in front like the current one does. I didn’t remove the tags. - The file I have linked to is just the openhab.log as it appears at this time in my /var/log/openhab/ directory.

OK, let me see if I can put a degree symbol in there. I do have my default units set to imperial.