OpenZWave / open-zwave

a C++ library to control Z-Wave Networks via a USB Z-Wave Controller.
http://www.openzwave.net/
GNU Lesser General Public License v3.0
1.05k stars 918 forks source link

Use supervision command to set thermostat setpoint #2525

Closed markruys closed 3 years ago

markruys commented 3 years ago

Some devices like the Fibaro FGT001 Heat Controller won't accept a ThermostatSetpointCmd_Get right immediate after a ThermostatSetpointCmd_Set. The device returns instead:

0x22 = COMMAND_CLASS_APPLICATION_STATUS (See 4.2.2 Application Busy Command in SDS13782 Z-Wave Management Command Class Specification.pdf) 0x01 = APPLICATION_BUSY 0x01 = "Try again in Wait Time seconds" 0x02 = two seconds...

One solution would be to retry the ThermostatSetpointCmd_Get after 2 seconds. A more efficient approach is to encapsulate the ThermostatSetpointCmd_Set with a supervision CC. This was proposed in issue #1971 and is implemented in this PR. It works like this:

2020-12-12 22:29:53.430 Info, Node009, Value::Set - COMMAND_CLASS_THERMOSTAT_SETPOINT - Heating 1 - 1 - 1 - 21
2020-12-12 22:29:53.430 Detail, Node009, Queuing (Send) MultiChannel Encapsulated (instance=1): Supervisioned: ThermostatSetpointCmd_Set (Node=9): 0x01, 0x14, 0x00, 0x13, 0x09, 0x0d, 0x60, 0x0d, 0x01, 0x01, 0x6c, 0x01, 0x81, 0x05, 0x43, 0x01, 0x01, 0x01, 0x15, 0x25, 0x2e, 0x24
2020-12-12 22:29:53.431 Detail, 
2020-12-12 22:29:53.431 Info, Node009, Sending (Send) message (Callback ID=0x2e, Expected Reply=0x13) - MultiChannel Encapsulated (instance=1): Supervisioned: ThermostatSetpointCmd_Set (Node=9): 0x01, 0x14, 0x00, 0x13, 0x09, 0x0d, 0x60, 0x0d, 0x01, 0x01, 0x6c, 0x01, 0x81, 0x05, 0x43, 0x01, 0x01, 0x01, 0x15, 0x25, 0x2e, 0x24
2020-12-12 22:29:53.431 Info, Node009, Encrypted Flag is 0
2020-12-12 22:29:53.440 Detail, Node009,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2020-12-12 22:29:53.440 Detail, Node009,   ZW_SEND_DATA delivered to Z-Wave stack
2020-12-12 22:29:54.747 Detail, Node009,   Received: 0x01, 0x07, 0x00, 0x13, 0x2e, 0x00, 0x00, 0x83, 0x46
2020-12-12 22:29:54.747 Detail, Node009,   ZW_SEND_DATA Request with callback ID 0x2e received (expected 0x2e)
2020-12-12 22:29:54.747 Info, Node009, Request RTT 1315 Average Request RTT 672
2020-12-12 22:29:54.747 Detail, Node009,   Expected callbackId was received
2020-12-12 22:29:54.747 Detail, Node009,   Expected reply was received
2020-12-12 22:29:54.747 Detail, Node009,   Message transaction complete
2020-12-12 22:29:54.747 Detail, 
2020-12-12 22:29:54.747 Detail, Node009, Removing current message
2020-12-12 22:29:54.870 Detail, Node009,   Received: 0x01, 0x0f, 0x00, 0x04, 0x00, 0x09, 0x09, 0x60, 0x0d, 0x01, 0x01, 0x6c, 0x02, 0x01, 0xff, 0x00, 0x09
2020-12-12 22:29:54.870 Detail, 
2020-12-12 22:29:54.870 Info, Node009, Received a MultiChannelEncap from node 9, endpoint 1 for Command Class COMMAND_CLASS_SUPERVISION
2020-12-12 22:29:54.870 Info, Node009, Received SupervisionReport: session id 1, status 0xff, duration 0 sec, more status updates 0
2020-12-12 22:29:54.870 Detail, Node009, Value Updated: old value=21.5, new value=21, type=decimal
2020-12-12 22:29:54.870 Detail, Node009, Changes to this value are not verified
2020-12-12 22:29:54.870 Info, Node009, Confirmed thermostat setpoint Heating 1 to 21C
2020-12-12 22:29:54.871 Detail, Node009, Notification: ValueChanged CC: COMMAND_CLASS_THERMOSTAT_SETPOINT Instance: 1 Index: 1

I consider this code of beta quality as I'm not familiar with the Z-Wave protocol in full depth. So feedback on where (and possibly how) to improve this PR is greatly appreciated. In my code I added a few times the 'TODO' label. Having said that, the PR works quite well for me for a few months now.

Room for improvements:

nebuohyrrah commented 3 years ago

I've made a windows build in visual studio 2019 with this pull request to try out. After changing a few 'uint' to 'uint8' it compiled fine. The supervision command class is used to set the setpoint and and thermostat mode. This works fine, as I could verify this at the node itself.

When doing a ThermostatSetpointCmd_Get or poll a reply is received but the follwing error is shown: Error, Node014, Received a MultiChannelEncap for endpoint 1 for Command Class 108, which we can't find

Is something missing in the code or did I miss something? I have too little experience with c++ to fiqure it out.

markruys commented 3 years ago

I've made a windows build in visual studio 2019 with this pull request to try out. After changing a few 'uint' to 'uint8' it compiled fine.

If you show us which, we can change it in the PR.

The supervision command class is used to set the setpoint and and thermostat mode. This works fine, as I could verify this at the node itself.

When doing a ThermostatSetpointCmd_Get or poll a reply is received but the follwing error is shown: Error, Node014, Received a MultiChannelEncap for endpoint 1 for Command Class 108, which we can't find

Is something missing in the code or did I miss something? I have too little experience with c++ to fiqure it out.

Command Class 108 is the Supervision CC. It's (for me) hard to tell what's going wrong without a detailed debug log like shown in the first post.

nebuohyrrah commented 3 years ago

The lines I had to change to make a build without errors are :

I changed 'uint' to 'uint8', don't know if 'uint8' is right.

I tried to get the debug log, but this time I didn't copy the database and ozwcache from the raspberry pi. That made a small difference as now the command class is recognized correctly, but it doesn't update the setpoint in the software.

For the FGT001 (Fibaro heat controller) At the node the setpoint is received. However the value is not updated in ozw, the logs stop after the supervision report "Succes". Also when the setpoint is polled.

2021-01-24 16:16:52.141 Detail, Node015, Queuing (Send) MultiChannel Encapsulated (instance=1): Supervisioned: ThermostatSetpointCmd_Set (Node=15): 0x01, 0x14, 0x00, 0x13, 0x0f, 0x0d, 0x60, 0x0d, 0x01, 0x01, 0x6c, 0x01, 0x84, 0x05, 0x43, 0x01, 0x01, 0x21, 0xc3, 0x25, 0x44, 0xbb
2021-01-24 16:16:52.147 Detail, 
2021-01-24 16:16:52.157 Info, Node015, Sending (Send) message (Callback ID=0x44, Expected Reply=0x13) - MultiChannel Encapsulated (instance=1): Supervisioned: ThermostatSetpointCmd_Set (Node=15): 0x01, 0x14, 0x00, 0x13, 0x0f, 0x0d, 0x60, 0x0d, 0x01, 0x01, 0x6c, 0x01, 0x84, 0x05, 0x43, 0x01, 0x01, 0x21, 0xc3, 0x25, 0x44, 0xbb
2021-01-24 16:16:52.165 Info, Node015, Encrypted Flag is 0
2021-01-24 16:16:52.178 Detail, Node015,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2021-01-24 16:16:52.186 Detail, Node015,   ZW_SEND_DATA delivered to Z-Wave stack
2021-01-24 16:16:53.489 Detail, Node015,   Received: 0x01, 0x07, 0x00, 0x13, 0x44, 0x00, 0x00, 0x83, 0x2c
2021-01-24 16:16:53.498 Detail, Node015,   ZW_SEND_DATA Request with callback ID 0x44 received (expected 0x44)
2021-01-24 16:16:53.505 Info, Node015, Request RTT 1332 Average Request RTT 724
2021-01-24 16:16:53.513 Detail, Node015,   Expected callbackId was received
2021-01-24 16:16:53.519 Detail, Node015,   Expected reply was received
2021-01-24 16:16:53.525 Detail, Node015,   Message transaction complete
2021-01-24 16:16:53.531 Detail, 
2021-01-24 16:16:53.538 Detail, Node015, Removing current message
2021-01-24 16:16:53.733 Detail, Node015,   Received: 0x01, 0x0f, 0x00, 0x04, 0x00, 0x0f, 0x09, 0x60, 0x0d, 0x01, 0x01, 0x6c, 0x02, 0x04, 0xff, 0x00, 0x0a
2021-01-24 16:16:53.741 Detail, 
2021-01-24 16:16:53.748 Info, Node015, Received a MultiChannelEncap from node 15, endpoint 1 for Command Class COMMAND_CLASS_SUPERVISION
2021-01-24 16:16:53.754 Info, Node015, Received SupervisionReport: session id 4, status 0xff, duration 0 sec, more status updates 0

2021-01-24 16:19:15.569 Detail, Node015, Queuing (Poll) MultiChannel Encapsulated (instance=1): Supervisioned: ThermostatSetpointCmd_Get (Node=15): 0x01, 0x12, 0x00, 0x13, 0x0f, 0x0b, 0x60, 0x0d, 0x01, 0x01, 0x6c, 0x01, 0xcd, 0x03, 0x43, 0x02, 0x01, 0x25, 0x4a, 0x1b
2021-01-24 16:19:15.575 Detail, 
2021-01-24 16:19:15.584 Info, Node015, Sending (Poll) message (Callback ID=0x4a, Expected Reply=0x04) - MultiChannel Encapsulated (instance=1): Supervisioned: ThermostatSetpointCmd_Get (Node=15): 0x01, 0x12, 0x00, 0x13, 0x0f, 0x0b, 0x60, 0x0d, 0x01, 0x01, 0x6c, 0x01, 0xcd, 0x03, 0x43, 0x02, 0x01, 0x25, 0x4a, 0x1b
2021-01-24 16:19:15.591 Info, Node015, Encrypted Flag is 0
2021-01-24 16:19:15.603 Detail, Node015,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2021-01-24 16:19:15.610 Detail, Node015,   ZW_SEND_DATA delivered to Z-Wave stack
2021-01-24 16:19:16.903 Detail, Node015,   Received: 0x01, 0x07, 0x00, 0x13, 0x4a, 0x00, 0x00, 0x83, 0x22
2021-01-24 16:19:16.911 Detail, Node015,   ZW_SEND_DATA Request with callback ID 0x4a received (expected 0x4a)
2021-01-24 16:19:16.917 Info, Node015, Request RTT 1319 Average Request RTT 709
2021-01-24 16:19:16.923 Detail, Node015,   Expected callbackId was received
2021-01-24 16:19:16.930 Detail, Node015,   Received: 0x01, 0x0f, 0x00, 0x04, 0x00, 0x0f, 0x09, 0x60, 0x0d, 0x01, 0x01, 0x6c, 0x02, 0x0d, 0x02, 0x00, 0xfe
2021-01-24 16:19:16.937 Detail, 
2021-01-24 16:19:16.944 Info, Node015, Response RTT 1346 Average Response RTT 795
2021-01-24 16:19:16.951 Info, Node015, Received a MultiChannelEncap from node 15, endpoint 1 for Command Class COMMAND_CLASS_SUPERVISION
2021-01-24 16:19:16.957 Info, Node015, Received SupervisionReport: session id 13, status 0x02, duration 0 sec, more status updates 0
2021-01-24 16:19:16.964 Detail, Node015,   Expected reply and command class was received
2021-01-24 16:19:16.970 Detail, Node015,   Message transaction complete

I also own a couple of Eurotronic SPIRITZ Wall Radiator Thermostat+ devices and when changing the setpoint it does not update the setpoint in ozw and the lcd of the node has not changed.

2021-01-24 16:37:04.087 Info, Node032, Value::Set - COMMAND_CLASS_THERMOSTAT_SETPOINT - Heating 1 - 1 - 1 - 18
2021-01-24 16:37:04.094 Detail, Node032, Queuing (Send) MultiChannel Encapsulated (instance=1): Supervisioned: ThermostatSetpointCmd_Set (Node=32): 0x01, 0x14, 0x00, 0x13, 0x20, 0x0d, 0x60, 0x0d, 0x01, 0x00, 0x6c, 0x01, 0x87, 0x05, 0x43, 0x01, 0x01, 0x01, 0x12, 0x25, 0x62, 0x41
2021-01-24 16:37:04.101 Detail, 
2021-01-24 16:37:04.109 Info, Node032, Sending (Send) message (Callback ID=0x62, Expected Reply=0x13) - MultiChannel Encapsulated (instance=1): Supervisioned: ThermostatSetpointCmd_Set (Node=32): 0x01, 0x14, 0x00, 0x13, 0x20, 0x0d, 0x60, 0x0d, 0x01, 0x00, 0x6c, 0x01, 0x87, 0x05, 0x43, 0x01, 0x01, 0x01, 0x12, 0x25, 0x62, 0x41
2021-01-24 16:37:04.117 Info, Node032, Encrypted Flag is 0
2021-01-24 16:37:04.132 Detail, Node032,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2021-01-24 16:37:04.139 Detail, Node032,   ZW_SEND_DATA delivered to Z-Wave stack
2021-01-24 16:37:05.416 Detail, Node032,   Received: 0x01, 0x07, 0x00, 0x13, 0x62, 0x00, 0x00, 0x80, 0x09
2021-01-24 16:37:05.424 Detail, Node032,   ZW_SEND_DATA Request with callback ID 0x62 received (expected 0x62)
2021-01-24 16:37:05.433 Info, Node032, Request RTT 1305 Average Request RTT 1152
2021-01-24 16:37:05.440 Detail, Node032,   Expected callbackId was received
2021-01-24 16:37:05.448 Detail, Node032,   Expected reply was received
2021-01-24 16:37:05.455 Detail, Node032,   Message transaction complete
2021-01-24 16:37:05.463 Detail, 
2021-01-24 16:37:05.470 Detail, Node032, Removing current message

Hopefully these logs are of any use.

markruys commented 3 years ago

The lines I had to change to make a build without errors are :

  • Node.h Ln:916 uint GetSupervisionSessionId(uint8 _command_class_id);
  • Node.cpp Ln:4058 uint Node::GetSupervisionSessionId(uint8 _command_class_id)
  • ThermostatSetpoint.h Ln:91 uint m_supervision_session_id;
  • Supervision.h Ln:109 static uint m_session_id;
  • Supervision.h Ln:110 uint m_command_class_id;
  • Supervision.cpp Ln:44 uint Supervision::m_session_id = 0;

I changed 'uint' to 'uint8', don't know if 'uint8' is right.

Yes, that's right. I commited these fixes.

For the other issues you mentioned, I found an ugly bug in my code which I just fixed. I think it will address the issues you mentioned. Can you give another try?

nebuohyrrah commented 3 years ago

I gave it another try. I seems the Supervision command class is working.

2021-01-27 19:35:23.443 Info, Node015, Value::Set - COMMAND_CLASS_THERMOSTAT_SETPOINT - Heating 1 - 1 - 1 - 19.5
2021-01-27 19:35:23.448 Detail, Node015, Queuing (Send) MultiChannel Encapsulated (instance=1): Supervisioned: ThermostatSetpointCmd_Set (Node=15): 0x01, 0x14, 0x00, 0x13, 0x0f, 0x0d, 0x60, 0x0d, 0x01, 0x01, 0x6c, 0x01, 0x81, 0x05, 0x43, 0x01, 0x01, 0x21, 0xc3, 0x25, 0xdd, 0x27
2021-01-27 19:35:23.455 Detail, 
2021-01-27 19:35:23.463 Info, Node015, Sending (Send) message (Callback ID=0xdd, Expected Reply=0x13) - MultiChannel Encapsulated (instance=1): Supervisioned: ThermostatSetpointCmd_Set (Node=15): 0x01, 0x14, 0x00, 0x13, 0x0f, 0x0d, 0x60, 0x0d, 0x01, 0x01, 0x6c, 0x01, 0x81, 0x05, 0x43, 0x01, 0x01, 0x21, 0xc3, 0x25, 0xdd, 0x27
2021-01-27 19:35:23.470 Info, Node015, Encrypted Flag is 0
2021-01-27 19:35:23.484 Detail, Node015,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2021-01-27 19:35:23.492 Detail, Node015,   ZW_SEND_DATA delivered to Z-Wave stack
2021-01-27 19:35:24.768 Detail, Node015,   Received: 0x01, 0x07, 0x00, 0x13, 0xdd, 0x00, 0x00, 0x81, 0xb7
2021-01-27 19:35:24.776 Detail, Node015,   ZW_SEND_DATA Request with callback ID 0xdd received (expected 0xdd)
2021-01-27 19:35:24.783 Info, Node015, Request RTT 1304 Average Request RTT 672
2021-01-27 19:35:24.789 Detail, Node015,   Expected callbackId was received
2021-01-27 19:35:24.795 Detail, Node015,   Expected reply was received
2021-01-27 19:35:24.801 Detail, Node015,   Message transaction complete
2021-01-27 19:35:24.808 Detail, 
2021-01-27 19:35:24.814 Detail, Node015, Removing current message
2021-01-27 19:35:25.030 Detail, Node015,   Received: 0x01, 0x0f, 0x00, 0x04, 0x00, 0x0f, 0x09, 0x60, 0x0d, 0x01, 0x01, 0x6c, 0x02, 0x01, 0xff, 0x00, 0x0f
2021-01-27 19:35:25.036 Detail, 
2021-01-27 19:35:25.043 Info, Node015, Received a MultiChannelEncap from node 15, endpoint 1 for Command Class COMMAND_CLASS_SUPERVISION
2021-01-27 19:35:25.049 Info, Node015, Received SupervisionReport: session id 1, status 0xff, duration 0 sec, more status updates 0

The value is still not updated. With some extra log lines added I could pinpoint that the following if-statement is false. ThermostatSetpoint.cpp line 270

if (Internal::VC::ValueDecimal* value = static_cast<Internal::VC::ValueDecimal*>(GetValue(_instance, _index)))

markruys commented 3 years ago

The value is still not updated. With some extra log lines added I could pinpoint that the following if-statement is false. ThermostatSetpoint.cpp line 270

if (Internal::VC::ValueDecimal* value = static_cast<Internal::VC::ValueDecimal*>(GetValue(_instance, _index)))

Could you change these lines to:

        if ( m_supervision_session_id == _session_id )
        {
                    uint16 const _index = m_value->GetID().GetIndex();
                    uint32 const instance = m_value->GetID().GetInstance();
                    Log::Write(LogLevel_Info, GetNodeId(), "DEBUG SupervisionSessionSuccess(%d, %d): GetValue(%d %d) with id %d", _session_id, _instance, instance, _index, m_value->GetID());
                    if (Internal::VC::ValueDecimal* value = static_cast<Internal::VC::ValueDecimal*>(GetValue(instance, _index)))
                    {

It might fix the issue. If not, please post the resulting debug log again.

nebuohyrrah commented 3 years ago

Unfortunately it doesn't solve the issue. The values for instance and _index don't seem to be correct to me.

2021-01-30 17:18:34.013 Info, Node015, Value::Set - COMMAND_CLASS_THERMOSTAT_SETPOINT - Heating 1 - 1 - 1 - 20
2021-01-30 17:18:34.023 Detail, Node015, Queuing (Send) MultiChannel Encapsulated (instance=1): Supervisioned: ThermostatSetpointCmd_Set (Node=15): 0x01, 0x14, 0x00, 0x13, 0x0f, 0x0d, 0x60, 0x0d, 0x01, 0x01, 0x6c, 0x01, 0x81, 0x05, 0x43, 0x01, 0x01, 0x01, 0x14, 0x25, 0xdf, 0xd2
2021-01-30 17:18:34.040 Detail, 
2021-01-30 17:18:34.052 Info, Node015, Sending (Send) message (Callback ID=0xdf, Expected Reply=0x13) - MultiChannel Encapsulated (instance=1): Supervisioned: ThermostatSetpointCmd_Set (Node=15): 0x01, 0x14, 0x00, 0x13, 0x0f, 0x0d, 0x60, 0x0d, 0x01, 0x01, 0x6c, 0x01, 0x81, 0x05, 0x43, 0x01, 0x01, 0x01, 0x14, 0x25, 0xdf, 0xd2
2021-01-30 17:18:34.070 Info, Node015, Encrypted Flag is 0
2021-01-30 17:18:34.092 Detail, Node015,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2021-01-30 17:18:34.108 Detail, Node015,   ZW_SEND_DATA delivered to Z-Wave stack
2021-01-30 17:18:35.363 Detail, Node015,   Received: 0x01, 0x07, 0x00, 0x13, 0xdf, 0x00, 0x00, 0x80, 0xb4
2021-01-30 17:18:35.396 Detail, Node015,   ZW_SEND_DATA Request with callback ID 0xdf received (expected 0xdf)
2021-01-30 17:18:35.421 Info, Node015, Request RTT 1338 Average Request RTT 700
2021-01-30 17:18:35.429 Detail, Node015,   Expected callbackId was received
2021-01-30 17:18:35.455 Detail, Node015,   Expected reply was received
2021-01-30 17:18:35.462 Detail, Node015,   Message transaction complete
2021-01-30 17:18:35.485 Detail, 
2021-01-30 17:18:35.492 Detail, Node015, Removing current message
2021-01-30 17:18:35.639 Detail, Node015,   Received: 0x01, 0x0f, 0x00, 0x04, 0x00, 0x0f, 0x09, 0x60, 0x0d, 0x01, 0x01, 0x6c, 0x02, 0x01, 0xff, 0x00, 0x0f
2021-01-30 17:18:35.651 Detail, 
2021-01-30 17:18:35.665 Info, Node015, Received a MultiChannelEncap from node 15, endpoint 1 for Command Class COMMAND_CLASS_SUPERVISION
2021-01-30 17:18:35.681 Info, Node015, Received SupervisionReport: session id 1, status 0xff, duration 0 sec, more status updates 0
2021-01-30 17:18:35.692 Info, Node015, DEBUG SupervisionSessionSuccess(1, 1): GetValue(221 56797) with id -572662307
markruys commented 3 years ago

In ThermostatSetpoint::SupervisionSessionSuccess() you have m_value->GetID() -572662307 (0xdddddddd) which seems a weird value to me. It might be that m_value is corrupt. As I can't reproduce the issue, and as I'm lacking in depth knowledge of the inner workings of this library, I think we need some guidance of a core ozw developer.

nebuohyrrah commented 3 years ago

I took a dive in the code and probably discovered what is going on. When changing the thermostat setpoint, a copy of the value is made to process the set command and is deleted afterwards. When the supervision command returns with a succes message, the tempValue is already deleted and the pointer points to garbage.

bool ValueDecimal::Set(string const& _value)
            {
                // create a temporary copy of this value to be submitted to the Set() call and set its value to the function param
                ValueDecimal* tempValue = new ValueDecimal(*this);
                tempValue->m_value = _value;

                // Set the value in the device.
                bool ret = ((Value*) tempValue)->Set();

                // clean up the temporary value
                delete tempValue;

                return ret;
            }

A possible solution would be to make another copy of the data and delete it after a supervision succes. However if for some reason there is no supervision success message received, there is a possible memory leak.

Now I used the string m_newValue; // a new value to be set on the appropriate device variable to store the requested setpoint. It seems to be unused in the current code. I only need to figure out where to store the index of the value. For now I put it fixed at 1 and this works for the 'normally used' setpoints, but heat eco and heat maximum etc. use other indexes.

Any ideas where to store the index? Maybe similar to the m_supervision_session_id?

markruys commented 3 years ago

@nebuohyrrah, I've implemented the suggested fix which seems reasonable to me.

I'm afraid I've polluted this PR with many non related commits, so I've created a new PR: #2584. I'll close this PR.