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

Incorrect color "Target Value" #2447

Open jtronicus opened 3 years ago

jtronicus commented 3 years ago

I had originally posted this on the Zwave2MQTT github page, but the more I look at it the more it seems like an OZW issue instead of Zwave2MQTT.

Version

Build/Run method

Zwave2Mqtt version: 4.0.5 Openzwave Version: 1.6.1392

Describe the bug Web Interface and MQTT do not appear to populate the "Target Color" field correctly. I am not sure if this is an issue with Zwave2MQTT, or is an issue in OZW itself

To Reproduce Steps to reproduce the behavior:

  1. Change the color on a device that supports Command Class Switch Color v2 or v3 (device needs to have a duration parameter set so it slowly transitions to the new color)
  2. Target color is updated with the instantaneous value, not the Target value

Expected behavior Target Color field should populate with the desired color at the end of the transition

Additional context Example: Color Starts at value #00FF000000 (green) I attempt to change the color to #0000FF0000 (blue) OZW issues the Color Switch Set command to change the color, and immediately issues the Color Switch Get commands to return results. Device reports the current (in transition) color as #00F60C0000 and the Target Color as #0000FF0000 as expected, but the Web interface/MQTT shows the Target Color as #00F6C00000

zniffer packet data: image

Web Interface values: image

OZW Logs (note: these are filtered logs):

2020-10-30 22:11:20.632 Info, Node041, Value::Set - COMMAND_CLASS_COLOR - Color - 0 - 1 - #0000ff0000
2020-10-30 22:11:20.632 Info, Node041, Color::SetValue - Setting Color value
2020-10-30 22:11:20.632 Detail, Node041, Queuing (Send) ColorCmd_Set (Node=41): 0x01, 0x15, 0x00, 0x13, 0x29, 0x0e, 0x33, 0x05, 0x05, 0x02, 0x00, 0x03, 0x00, 0x04, 0xff, 0x00, 0x00, 0x01, 0x00, 0x03, 0x25, 0x7c, 0x4c
2020-10-30 22:11:20.632 Detail, Node041, Queuing (Send) ColorCmd_Get (Node=41): 0x01, 0x0a, 0x00, 0x13, 0x29, 0x03, 0x33, 0x03, 0x00, 0x25, 0x7d, 0xa4
2020-10-30 22:11:20.632 Detail, Node041, Queuing (Send) ColorCmd_Get (Node=41): 0x01, 0x0a, 0x00, 0x13, 0x29, 0x03, 0x33, 0x03, 0x01, 0x25, 0x7e, 0xa6
2020-10-30 22:11:20.632 Detail, Node041, Queuing (Send) ColorCmd_Get (Node=41): 0x01, 0x0a, 0x00, 0x13, 0x29, 0x03, 0x33, 0x03, 0x02, 0x25, 0x7f, 0xa4
2020-10-30 22:11:20.632 Detail, Node041, Queuing (Send) ColorCmd_Get (Node=41): 0x01, 0x0a, 0x00, 0x13, 0x29, 0x03, 0x33, 0x03, 0x03, 0x25, 0x80, 0x5a
2020-10-30 22:11:20.632 Detail, Node041, Queuing (Send) ColorCmd_Get (Node=41): 0x01, 0x0a, 0x00, 0x13, 0x29, 0x03, 0x33, 0x03, 0x04, 0x25, 0x81, 0x5c
2020-10-30 22:11:20.632 Detail,
2020-10-30 22:11:20.632 Info, Node041, Sending (Send) message (Callback ID=0x7c, Expected Reply=0x00) - ColorCmd_Set (Node=41): 0x01, 0x15, 0x00, 0x13, 0x29, 0x0e, 0x33, 0x05, 0x05, 0x02, 0x00, 0x03, 0x00, 0x04, 0xff, 0x00, 0x00, 0x01, 0x00, 0x03, 0x25, 0x7c, 0x4c
2020-10-30 22:11:20.632 Info, Node041, Encrypted Flag is 0
2020-10-30 22:11:20.641 Detail, Node041,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2020-10-30 22:11:20.641 Detail, Node041,   ZW_SEND_DATA delivered to Z-Wave stack
2020-10-30 22:11:20.656 Detail, Node041,   Received: 0x01, 0x07, 0x00, 0x13, 0x7c, 0x00, 0x00, 0x02, 0x95
2020-10-30 22:11:20.656 Detail, Node041,   ZW_SEND_DATA Request with callback ID 0x7c received (expected 0x7c)
2020-10-30 22:11:20.656 Info, Node041, Request RTT 23 Average Request RTT 22
2020-10-30 22:11:20.656 Detail, Node041,   Expected callbackId was received
2020-10-30 22:11:20.656 Detail, Node041,   Message transaction complete
2020-10-30 22:11:20.656 Detail,
2020-10-30 22:11:20.656 Detail, Node041, Removing current message
2020-10-30 22:11:20.656 Detail,
2020-10-30 22:11:20.656 Info, Node041, Sending (Send) message (Callback ID=0x7d, Expected Reply=0x04) - ColorCmd_Get (Node=41): 0x01, 0x0a, 0x00, 0x13, 0x29, 0x03, 0x33, 0x03, 0x00, 0x25, 0x7d, 0xa4
2020-10-30 22:11:20.656 Info, Node041, Encrypted Flag is 0
2020-10-30 22:11:20.664 Detail, Node041,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2020-10-30 22:11:20.664 Detail, Node041,   ZW_SEND_DATA delivered to Z-Wave stack
2020-10-30 22:11:20.672 Info, Node041, Value::Set - COMMAND_CLASS_SWITCH_MULTILEVEL - Level - 0 - 1 - 99
2020-10-30 22:11:20.673 Info, Node041, SwitchMultilevel::Set - Setting to level 99
2020-10-30 22:11:20.673 Info, Node041,   Duration: 0 seconds
2020-10-30 22:11:20.673 Detail, Node041, Queuing (Send) SwitchMultilevelCmd_Set (Node=41): 0x01, 0x0b, 0x00, 0x13, 0x29, 0x04, 0x26, 0x01, 0x63, 0x00, 0x25, 0x82, 0x29
2020-10-30 22:11:20.673 Detail, Node041, Queuing (Send) SwitchMultilevelCmd_Get (Node=41): 0x01, 0x09, 0x00, 0x13, 0x29, 0x02, 0x26, 0x02, 0x25, 0x83, 0x4c
2020-10-30 22:11:20.678 Detail, Node041,   Received: 0x01, 0x07, 0x00, 0x13, 0x7d, 0x00, 0x00, 0x02, 0x94
2020-10-30 22:11:20.678 Detail, Node041,   ZW_SEND_DATA Request with callback ID 0x7d received (expected 0x7d)
2020-10-30 22:11:20.678 Info, Node041, Request RTT 21 Average Request RTT 21
2020-10-30 22:11:20.678 Detail, Node041,   Expected callbackId was received
2020-10-30 22:11:20.689 Detail, Node041,   Received: 0x01, 0x0c, 0x00, 0x04, 0x00, 0x29, 0x06, 0x33, 0x04, 0x00, 0x00, 0x00, 0x03, 0xec
2020-10-30 22:11:20.689 Detail,
2020-10-30 22:11:20.689 Info, Node041, Response RTT 32 Average Response RTT 33
2020-10-30 22:11:20.689 Detail, Node041,   Expected reply and command class was received
2020-10-30 22:11:20.689 Detail, Node041,   Message transaction complete
2020-10-30 22:11:20.689 Detail,
2020-10-30 22:11:20.689 Detail, Node041, Removing current message
2020-10-30 22:11:20.689 Detail,
2020-10-30 22:11:20.689 Info, Node041, Sending (Send) message (Callback ID=0x7e, Expected Reply=0x04) - ColorCmd_Get (Node=41): 0x01, 0x0a, 0x00, 0x13, 0x29, 0x03, 0x33, 0x03, 0x01, 0x25, 0x7e, 0xa6
2020-10-30 22:11:20.689 Info, Node041, Encrypted Flag is 0
2020-10-30 22:11:20.699 Detail, Node041,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2020-10-30 22:11:20.699 Detail, Node041,   ZW_SEND_DATA delivered to Z-Wave stack
2020-10-30 22:11:20.718 Detail, Node041,   Received: 0x01, 0x07, 0x00, 0x13, 0x7e, 0x00, 0x00, 0x03, 0x96
2020-10-30 22:11:20.718 Detail, Node041,   ZW_SEND_DATA Request with callback ID 0x7e received (expected 0x7e)
2020-10-30 22:11:20.718 Info, Node041, Request RTT 28 Average Request RTT 24
2020-10-30 22:11:20.718 Detail, Node041,   Expected callbackId was received
2020-10-30 22:11:20.730 Detail, Node041,   Received: 0x01, 0x0c, 0x00, 0x04, 0x00, 0x29, 0x06, 0x33, 0x04, 0x01, 0x00, 0x00, 0x00, 0xee
2020-10-30 22:11:20.730 Detail,
2020-10-30 22:11:20.730 Info, Node041, Response RTT 40 Average Response RTT 36
2020-10-30 22:11:20.730 Detail, Node041,   Expected reply and command class was received
2020-10-30 22:11:20.730 Detail, Node041,   Message transaction complete
2020-10-30 22:11:20.730 Detail,
2020-10-30 22:11:20.730 Detail, Node041, Removing current message
2020-10-30 22:11:20.730 Detail,
2020-10-30 22:11:20.730 Info, Node041, Sending (Send) message (Callback ID=0x7f, Expected Reply=0x04) - ColorCmd_Get (Node=41): 0x01, 0x0a, 0x00, 0x13, 0x29, 0x03, 0x33, 0x03, 0x02, 0x25, 0x7f, 0xa4
2020-10-30 22:11:20.730 Info, Node041, Encrypted Flag is 0
2020-10-30 22:11:20.738 Detail, Node041,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2020-10-30 22:11:20.739 Detail, Node041,   ZW_SEND_DATA delivered to Z-Wave stack
2020-10-30 22:11:20.754 Detail, Node041,   Received: 0x01, 0x07, 0x00, 0x13, 0x7f, 0x00, 0x00, 0x02, 0x96
2020-10-30 22:11:20.754 Detail, Node041,   ZW_SEND_DATA Request with callback ID 0x7f received (expected 0x7f)
2020-10-30 22:11:20.754 Info, Node041, Request RTT 23 Average Request RTT 23
2020-10-30 22:11:20.754 Detail, Node041,   Expected callbackId was received
2020-10-30 22:11:20.768 Detail, Node041,   Received: 0x01, 0x0c, 0x00, 0x04, 0x00, 0x29, 0x06, 0x33, 0x04, 0x02, 0x00, 0x00, 0x00, 0xed
2020-10-30 22:11:20.768 Detail,
2020-10-30 22:11:20.768 Info, Node041, Response RTT 37 Average Response RTT 36
2020-10-30 22:11:20.768 Detail, Node041,   Expected reply and command class was received
2020-10-30 22:11:20.768 Detail, Node041,   Message transaction complete
2020-10-30 22:11:20.768 Detail,
2020-10-30 22:11:20.768 Detail, Node041, Removing current message
2020-10-30 22:11:20.768 Detail,
2020-10-30 22:11:20.768 Info, Node041, Sending (Send) message (Callback ID=0x80, Expected Reply=0x04) - ColorCmd_Get (Node=41): 0x01, 0x0a, 0x00, 0x13, 0x29, 0x03, 0x33, 0x03, 0x03, 0x25, 0x80, 0x5a
2020-10-30 22:11:20.768 Info, Node041, Encrypted Flag is 0
2020-10-30 22:11:20.777 Detail, Node041,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2020-10-30 22:11:20.777 Detail, Node041,   ZW_SEND_DATA delivered to Z-Wave stack
2020-10-30 22:11:20.792 Detail, Node041,   Received: 0x01, 0x07, 0x00, 0x13, 0x80, 0x00, 0x00, 0x02, 0x69
2020-10-30 22:11:20.792 Detail, Node041,   ZW_SEND_DATA Request with callback ID 0x80 received (expected 0x80)
2020-10-30 22:11:20.792 Info, Node041, Request RTT 23 Average Request RTT 23
2020-10-30 22:11:20.792 Detail, Node041,   Expected callbackId was received
2020-10-30 22:11:20.803 Detail, Node041,   Received: 0x01, 0x0c, 0x00, 0x04, 0x00, 0x29, 0x06, 0x33, 0x04, 0x03, 0xf6, 0x00, 0x03, 0x19
2020-10-30 22:11:20.803 Detail,
2020-10-30 22:11:20.803 Info, Node041, Response RTT 34 Average Response RTT 35
2020-10-30 22:11:20.803 Detail, Node041,   Expected reply and command class was received
2020-10-30 22:11:20.803 Detail, Node041,   Message transaction complete
2020-10-30 22:11:20.804 Detail,
2020-10-30 22:11:20.804 Detail, Node041, Removing current message
2020-10-30 22:11:20.804 Detail,
2020-10-30 22:11:20.804 Info, Node041, Sending (Send) message (Callback ID=0x81, Expected Reply=0x04) - ColorCmd_Get (Node=41): 0x01, 0x0a, 0x00, 0x13, 0x29, 0x03, 0x33, 0x03, 0x04, 0x25, 0x81, 0x5c
2020-10-30 22:11:20.804 Info, Node041, Encrypted Flag is 0
2020-10-30 22:11:20.812 Detail, Node041,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2020-10-30 22:11:20.812 Detail, Node041,   ZW_SEND_DATA delivered to Z-Wave stack
2020-10-30 22:11:20.827 Detail, Node041,   Received: 0x01, 0x07, 0x00, 0x13, 0x81, 0x00, 0x00, 0x03, 0x69
2020-10-30 22:11:20.827 Detail, Node041,   ZW_SEND_DATA Request with callback ID 0x81 received (expected 0x81)
2020-10-30 22:11:20.827 Info, Node041, Request RTT 23 Average Request RTT 23
2020-10-30 22:11:20.827 Detail, Node041,   Expected callbackId was received
2020-10-30 22:11:20.838 Detail, Node041,   Received: 0x01, 0x0c, 0x00, 0x04, 0x00, 0x29, 0x06, 0x33, 0x04, 0x04, 0x0c, 0xff, 0x03, 0x1b
2020-10-30 22:11:20.838 Detail,
2020-10-30 22:11:20.838 Info, Node041, Response RTT 34 Average Response RTT 34
2020-10-30 22:11:20.838 Info, Node041, Received a updated Color from Device: #00F60C0000
2020-10-30 22:11:20.838 Detail, Node041, Value Updated: old value=#F60C3B0000, new value=#00F60C0000, type=string
2020-10-30 22:11:20.838 Detail, Node041,        Target Value is Set to 35
2020-10-30 22:11:20.838 Detail, Node041, Value Updated: old value=17, new value=17, type=list
2020-10-30 22:11:20.838 Detail, Node041, Changes to this value are not verified
2020-10-30 22:11:20.838 Info, Node041, Received a updated Color Target from Device: #00F60C0000
2020-10-30 22:11:20.838 Detail, Node041, Value Updated: old value=#F60C3B0000, new value=#00F60C0000, type=string
2020-10-30 22:11:20.838 Detail, Node041, Changes to this value are not verified
2020-10-30 22:11:20.838 Detail, Node041,   Expected reply and command class was received
2020-10-30 22:11:20.838 Detail, Node041,   Message transaction complete
2020-10-30 22:11:20.838 Detail,
2020-10-30 22:11:20.838 Detail, Node041, Removing current message
2020-10-30 22:11:20.838 Detail, Node041, Notification: ValueChanged CC: COMMAND_CLASS_COLOR Instance: 1 Index: 0
2020-10-30 22:11:20.838 Detail, Node041, Notification: ValueRefreshed CC: COMMAND_CLASS_COLOR Instance: 1 Index: 1
2020-10-30 22:11:20.839 Detail, Node041, Notification: ValueChanged CC: COMMAND_CLASS_COLOR Instance: 1 Index: 5
2020-10-30 22:11:20.839 Detail,
2020-10-30 22:11:20.839 Info, Node041, Sending (Send) message (Callback ID=0x82, Expected Reply=0x13) - SwitchMultilevelCmd_Set (Node=41): 0x01, 0x0b, 0x00, 0x13, 0x29, 0x04, 0x26, 0x01, 0x63, 0x00, 0x25, 0x82, 0x29
2020-10-30 22:11:20.839 Info, Node041, Encrypted Flag is 0
2020-10-30 22:11:20.847 Detail, Node041,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2020-10-30 22:11:20.847 Detail, Node041,   ZW_SEND_DATA delivered to Z-Wave stack
2020-10-30 22:11:20.862 Detail, Node041,   Received: 0x01, 0x07, 0x00, 0x13, 0x82, 0x00, 0x00, 0x02, 0x6b
2020-10-30 22:11:20.862 Detail, Node041,   ZW_SEND_DATA Request with callback ID 0x82 received (expected 0x82)
2020-10-30 22:11:20.862 Info, Node041, Request RTT 23 Average Request RTT 23
2020-10-30 22:11:20.862 Detail, Node041,   Expected callbackId was received
2020-10-30 22:11:20.862 Detail, Node041,   Expected reply was received
2020-10-30 22:11:20.862 Detail, Node041,   Message transaction complete
2020-10-30 22:11:20.862 Detail,
2020-10-30 22:11:20.862 Detail, Node041, Removing current message
2020-10-30 22:11:20.862 Detail,
2020-10-30 22:11:20.862 Info, Node041, Sending (Send) message (Callback ID=0x83, Expected Reply=0x04) - SwitchMultilevelCmd_Get (Node=41): 0x01, 0x09, 0x00, 0x13, 0x29, 0x02, 0x26, 0x02, 0x25, 0x83, 0x4c
2020-10-30 22:11:20.862 Info, Node041, Encrypted Flag is 0
2020-10-30 22:11:20.872 Detail, Node041,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2020-10-30 22:11:20.872 Detail, Node041,   ZW_SEND_DATA delivered to Z-Wave stack
2020-10-30 22:11:20.884 Detail, Node041,   Received: 0x01, 0x07, 0x00, 0x13, 0x83, 0x00, 0x00, 0x02, 0x6a
2020-10-30 22:11:20.884 Detail, Node041,   ZW_SEND_DATA Request with callback ID 0x83 received (expected 0x83)
2020-10-30 22:11:20.884 Info, Node041, Request RTT 21 Average Request RTT 22
2020-10-30 22:11:20.884 Detail, Node041,   Expected callbackId was received
2020-10-30 22:11:20.896 Detail, Node041,   Received: 0x01, 0x0b, 0x00, 0x04, 0x00, 0x29, 0x05, 0x26, 0x03, 0x63, 0x63, 0x00, 0xf9
2020-10-30 22:11:20.896 Detail,
2020-10-30 22:11:20.896 Info, Node041, Response RTT 34 Average Response RTT 34
2020-10-30 22:11:20.896 Info, Node041, Received SwitchMultiLevel report: level=99
2020-10-30 22:11:20.896 Detail, Node041, Value Updated: old value=99, new value=99, type=byte
2020-10-30 22:11:20.896 Detail, Node041,        Target Value is Set to 99
2020-10-30 22:11:20.896 Detail, Node041, Value Updated: old value=99, new value=99, type=byte
2020-10-30 22:11:20.896 Detail, Node041, Changes to this value are not verified
2020-10-30 22:11:20.896 Detail, Node041, Value Updated: old value=0, new value=0, type=int
2020-10-30 22:11:20.896 Detail, Node041, Changes to this value are not verified
2020-10-30 22:11:20.896 Detail, Node041,   Expected reply and command class was received
2020-10-30 22:11:20.896 Detail, Node041,   Message transaction complete
2020-10-30 22:11:20.896 Detail,
2020-10-30 22:11:20.896 Detail, Node041, Removing current message
2020-10-30 22:11:20.897 Detail, Node041, Notification: ValueChanged CC: COMMAND_CLASS_SWITCH_MULTILEVEL Instance: 1 Index: 0
2020-10-30 22:11:20.897 Detail, Node041, Notification: ValueRefreshed CC: COMMAND_CLASS_SWITCH_MULTILEVEL Instance: 1 Index: 9
2020-10-30 22:11:20.897 Detail, Node041, Notification: ValueRefreshed CC: COMMAND_CLASS_SWITCH_MULTILEVEL Instance: 1 Index: 5

I took a stab at identifying where in the code the issue bight be (but I am not a programmer so I might be completely wrong) open-zwave/cpp/src/command_classes/Color.cpp (lines 383-393)

                    if (GetVersion() >= 3) 
                    {
                        string colorTargetStr = decodeColor(m_colorTargetValues);

                        if (Internal::VC::ValueString* color = static_cast<Internal::VC::ValueString*>(GetValue(_instance, ValueID_Index_Color::Target)))
                        {
                            Log::Write(LogLevel_Info, GetNodeId(), "Received a updated Color Target from Device: %s", colorStr.c_str());
                            color->OnValueRefreshed(colorStr);
                            color->Release();
                        }
                    }

Should this be colorTargetStr.c_str() and OnValueRefreshed(colorTargetStr) instead of ColorStr?