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

Qubino Smart Meter - Wrong switch states #1261

Open petrovcicklemen opened 7 years ago

petrovcicklemen commented 7 years ago

The Qubino Smart Meter (ZMNHTD1) device takes around 7 seconds to update the state of the relays internally. OpenZwave sends a GET command after every command, which switches the relays:

Because the Smart meter takes 7 seconds to update the state of its relays, it reports the previous, old state if it receives the SWITCH_BINARY_GET command before the 7 seconds. If you try to send a SWITCH_BINARY_SET before it is updated, it will send a SWITCH_BINARY_SET(state) command with the same state parameter value like the first time. The GUI of the Domoticz platform is updated only after it receives the unsolicited SWITCH_BINARY_REPORTS, which contain the correct state.

This is not an issue, if the user is using the Open Zwave Control Panel to control the devices, because the same command cannot be sent (comboboxes prevent this) multiple times. It becomes an issue in other platforms, which use this library (Domoticz, Jeedom). In both mentioned platforms, the user has to click two times on the widget, to turn the relays on/off.

Can this be fixed somehow?

Regards.

Fishwaldo commented 7 years ago

Could you try the following code change to cpp/src/command_classes/SwitchBinary.h virtual uint8 GetMaxVersion(){ return 2; }

the final file should look like: ` // From CommandClass

    virtual bool RequestState( uint32 const _requestFlags, uint8 const _instance, Driver::MsgQueue const _queue );

    virtual bool RequestValue( uint32 const _requestFlags, uint8 const _index, uint8 const _instance, Driver::MsgQueue const _queue );

    virtual uint8 const GetCommandClassId()const{ return StaticGetCommandClassId(); }

    virtual string const GetCommandClassName()const{ return StaticGetCommandClassName();}

    virtual bool HandleMsg( uint8 const* _data, uint32 const _length, uint32 const _instance = 1);

    virtual bool SetValue( Value const& _value );

    virtual void SetValueBasic( uint8 const _instance, uint8 const _value );

            virtual uint8 GetMaxVersion(){ return 2; }

`

Then recompile (make clean && make) and remove any zwcfg_*.xml file from the app directory, restart your application and send the log OZWLog.txt file.

Thanks

Fishwaldo commented 7 years ago

in the short term - you could enable polling for that ValueID. Then it would eventually update.

petrovcicklemen commented 7 years ago

I edited the file, removed the zwcfg_* files and recompilled. Using the three comboboxes, to switch the relays, does nothing (changing the state of the three comboboxes does not cause any relays to switch).

pic

I am attaching the log: OpenZwaveLog_30062017.txt

Fishwaldo commented 7 years ago

Its timing out on all SwitchBinary Set messages... did this work before? Can you double check the recompliation as well, as the changes I proposed should have triggered OZW to get the version of the CommandClass for SwitchBinary, but it did not:

2017-03-17 17:27:53.719 Info, Node004, Requesting Versions for COMMAND_CLASS_SWITCH_BINARY 2017-03-17 17:27:53.719 Info, Node004, Requesting Versions for COMMAND_CLASS_SWITCH_ALL 2017-03-17 17:27:53.719 Info, Node004, Requesting Versions for COMMAND_CLASS_METER 2017-03-17 17:27:53.719 Info, Node004, ok 2017-03-17 17:27:53.719 Detail, Node004, Queuing (Send) VersionCmd_CommandClassGet (Node=4): 0x01, 0x0a, 0x00, 0x13, 0x04, 0x03, 0x86, 0x13, 0x32, 0x25, 0x0e, 0x6d

petrovcicklemen commented 7 years ago

Sorry, I don't know what I did wrong earlier. I tried reincluding it and this time the relays worked, but the initial issue persists. I am sure I removed all the earlier zwcfg files and I ran the "make clean & make" commands.

I am attaching a picture of the edited file and the OpenZwaveLog.

editedfile OpenZwaveLog_30062017_2.txt

I think it didn't fetch the version of the SWITCH_BINARY class (line 430), again.

drcain1 commented 5 years ago

I'm noticing the same thing, and I wonder if it's related to #880 and #862 ? It takes around 4-5 seconds for the status to get reported correctly.

I've attached a dump of OZW_Log.txt when it happens.


2018-09-01 00:00:57.161 Detail, Node002,   Received: 0x01, 0x12, 0x00, 0x04, 0x00, 0x02, 0x0a, 0x32, 0x02, 0x21, 0x34, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0xbe, 0x00, 0x7a
2018-09-01 00:00:57.162 Detail, 
2018-09-01 00:00:57.162 Detail, Node002, Refreshed Value: old value=false, new value=false, type=bool
2018-09-01 00:00:57.162 Detail, Node002, Changes to this value are not verified
2018-09-01 00:00:57.162 Info, Node002, Received Meter report from node 2: Power=0.0W
2018-09-01 00:00:57.162 Detail, Node002, Refreshed Value: old value=0.0, new value=0.0, type=decimal
2018-09-01 00:00:57.163 Detail, Node002, Changes to this value are not verified
2018-09-01 00:00:57.163 Detail, Node002, Notification: ValueChanged
2018-09-01 00:00:57.193 Detail, Node002, Notification: ValueChanged
2018-09-01 00:01:33.309 Info, Node024, Value::Set - COMMAND_CLASS_SWITCH_BINARY - Switch - 0 - 2 - True
2018-09-01 00:01:33.309 Info, Node024, SwitchBinary::Set - Setting node 24 to On
2018-09-01 00:01:33.309 Detail, Node024, Queuing (Send) MultiChannel Encapsulated (instance=2): SwitchBinaryCmd_Set (Node=24): 0x01, 0x0e, 0x00, 0x13, 0x18, 0x07, 0x60, 0x0d, 0x01, 0x01, 0x25, 0x01, 0xff, 0x25, 0xb8, 0xd6
2018-09-01 00:01:33.310 Detail, Node024, Queuing (Send) MultiChannel Encapsulated (instance=2): SwitchBinaryCmd_Get (Node=24): 0x01, 0x0d, 0x00, 0x13, 0x18, 0x06, 0x60, 0x0d, 0x01, 0x01, 0x25, 0x02, 0x25, 0xb9, 0x29
2018-09-01 00:01:33.310 Detail, 
2018-09-01 00:01:33.310 Info, Node024, Sending (Send) message (Callback ID=0xb8, Expected Reply=0x13) - MultiChannel Encapsulated (instance=2): SwitchBinaryCmd_Set (Node=24): 0x01, 0x0e, 0x00, 0x13, 0x18, 0x07, 0x60, 0x0d, 0x01, 0x01, 0x25, 0x01, 0xff, 0x25, 0xb8, 0xd6
2018-09-01 00:01:33.317 Detail, Node024,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2018-09-01 00:01:33.318 Detail, Node024,   ZW_SEND_DATA delivered to Z-Wave stack
2018-09-01 00:01:33.337 Detail, Node024,   Received: 0x01, 0x18, 0x00, 0x13, 0xb8, 0x00, 0x00, 0x02, 0x00, 0xbc, 0x7f, 0x7f, 0x7f, 0x7f, 0x00, 0x00, 0x04, 0x00, 0x00, 0x00, 0x00, 0x03, 0x01, 0x00, 0x00, 0xf4
2018-09-01 00:01:33.338 Detail, Node024,   ZW_SEND_DATA Request with callback ID 0xb8 received (expected 0xb8)
2018-09-01 00:01:33.338 Info, Node024, Request RTT 27 Average Request RTT 26
2018-09-01 00:01:33.338 Detail,   Expected callbackId was received
2018-09-01 00:01:33.338 Detail,   Expected reply was received
2018-09-01 00:01:33.338 Detail,   Message transaction complete
2018-09-01 00:01:33.339 Detail, 
2018-09-01 00:01:33.339 Detail, Node024, Removing current message
2018-09-01 00:01:33.339 Detail, 
2018-09-01 00:01:33.340 Info, Node024, Sending (Send) message (Callback ID=0xb9, Expected Reply=0x04) - MultiChannel Encapsulated (instance=2): SwitchBinaryCmd_Get (Node=24): 0x01, 0x0d, 0x00, 0x13, 0x18, 0x06, 0x60, 0x0d, 0x01, 0x01, 0x25, 0x02, 0x25, 0xb9, 0x29
2018-09-01 00:01:33.346 Detail, Node024,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2018-09-01 00:01:33.347 Detail, Node024,   ZW_SEND_DATA delivered to Z-Wave stack
2018-09-01 00:01:33.365 Detail, Node024,   Received: 0x01, 0x18, 0x00, 0x13, 0xb9, 0x00, 0x00, 0x01, 0x00, 0xbe, 0x7f, 0x7f, 0x7f, 0x7f, 0x00, 0x00, 0x03, 0x00, 0x00, 0x00, 0x00, 0x03, 0x01, 0x00, 0x00, 0xf3
2018-09-01 00:01:33.366 Detail, Node024,   ZW_SEND_DATA Request with callback ID 0xb9 received (expected 0xb9)
2018-09-01 00:01:33.366 Info, Node024, Request RTT 25 Average Request RTT 25
2018-09-01 00:01:33.366 Detail,   Expected callbackId was received
2018-09-01 00:01:33.378 Detail, Node024,   Received: 0x01, 0x0f, 0x00, 0x04, 0x00, 0x18, 0x07, 0x60, 0x0d, 0x01, 0x01, 0x25, 0x03, 0x00, 0xbe, 0x00, 0x1e
2018-09-01 00:01:33.378 Detail, 
2018-09-01 00:01:33.379 Info, Node024, Response RTT 38 Average Response RTT 38
2018-09-01 00:01:33.379 Info, Node024, Received a MultiChannelEncap from node 24, endpoint 1 for Command Class COMMAND_CLASS_SWITCH_BINARY
2018-09-01 00:01:33.379 Info, Node024, Received SwitchBinary report from node 24: level=Off
2018-09-01 00:01:33.379 Detail, Node024, Refreshed Value: old value=false, new value=false, type=bool
2018-09-01 00:01:33.379 Detail, Node024, Changes to this value are not verified
2018-09-01 00:01:33.379 Detail, Node024,   Expected reply and command class was received
2018-09-01 00:01:33.380 Detail, Node024,   Message transaction complete
2018-09-01 00:01:33.380 Detail, 
2018-09-01 00:01:33.380 Detail, Node024, Removing current message
2018-09-01 00:01:33.380 Detail, Node024, Notification: ValueChanged
2018-09-01 00:01:37.229 Detail, Node024,   Received: 0x01, 0x1a, 0x00, 0x04, 0x00, 0x18, 0x12, 0x56, 0x01, 0x60, 0x0d, 0x01, 0x01, 0x32, 0x02, 0xa1, 0x6c, 0x00, 0x00, 0x03, 0x49, 0x00, 0x00, 0x2f, 0xcb, 0xbf, 0x00, 0x3d
2018-09-01 00:01:37.230 Detail, 
2018-09-01 00:01:37.230 Info, Node024, Received CRC16-command from node 24
2018-09-01 00:01:37.230 Info, Node024, Received a MultiChannelEncap from node 24, endpoint 1 for Command Class COMMAND_CLASS_METER
2018-09-01 00:01:37.230 Detail, Node024, Refreshed Value: old value=false, new value=false, type=bool
2018-09-01 00:01:37.231 Detail, Node024, Changes to this value are not verified
2018-09-01 00:01:37.231 Info, Node024, Received Meter report from node 24: Current=0.841A
2018-09-01 00:01:37.231 Detail, Node024, Refreshed Value: old value=0.013, new value=0.841, type=decimal
2018-09-01 00:01:37.231 Detail, Node024, Changes to this value are not verified
2018-09-01 00:01:37.231 Detail, Node024, Notification: ValueChanged
2018-09-01 00:01:37.262 Detail, Node024, Notification: ValueChanged
2018-09-01 00:01:37.635 Detail, Node024,   Received: 0x01, 0x1a, 0x00, 0x04, 0x00, 0x18, 0x12, 0x56, 0x01, 0x60, 0x0d, 0x01, 0x01, 0x32, 0x02, 0xa1, 0x94, 0x00, 0x00, 0x24, 0xa7, 0x00, 0x00, 0x4e, 0xad, 0xbf, 0x00, 0x0b
2018-09-01 00:01:37.635 Detail, 
2018-09-01 00:01:37.635 Info, Node024, Received CRC16-command from node 24
2018-09-01 00:01:37.636 Info, Node024, Received a MultiChannelEncap from node 24, endpoint 1 for Command Class COMMAND_CLASS_METER
2018-09-01 00:01:37.636 Detail, Node024, Refreshed Value: old value=false, new value=false, type=bool
2018-09-01 00:01:37.636 Detail, Node024, Changes to this value are not verified
2018-09-01 00:01:37.636 Info, Node024, Received Meter report from node 24: Power Factor=0.9383Power Factor
2018-09-01 00:01:37.636 Detail, Node024, Refreshed Value: old value=0.7359, new value=0.9383, type=decimal
2018-09-01 00:01:37.637 Detail, Node024, Changes to this value are not verified
2018-09-01 00:01:37.637 Detail, Node024, Notification: ValueChanged
2018-09-01 00:01:37.667 Detail, Node024, Notification: ValueChanged
2018-09-01 00:01:44.827 Detail, Node024,   Received: 0x01, 0x13, 0x00, 0x04, 0x00, 0x18, 0x0b, 0x56, 0x01, 0x60, 0x0d, 0x01, 0x01, 0x25, 0x03, 0xff, 0xc2, 0x5a, 0xbf, 0x00, 0x3f
2018-09-01 00:01:44.827 Detail, 
2018-09-01 00:01:44.827 Info, Node024, Received CRC16-command from node 24
2018-09-01 00:01:44.828 Info, Node024, Received a MultiChannelEncap from node 24, endpoint 1 for Command Class COMMAND_CLASS_SWITCH_BINARY
2018-09-01 00:01:44.828 Info, Node024, Received SwitchBinary report from node 24: level=On
2018-09-01 00:01:44.828 Detail, Node024, Refreshed Value: old value=false, new value=true, type=bool
2018-09-01 00:01:44.828 Detail, Node024, Changes to this value are not verified
2018-09-01 00:01:44.828 Detail, Node024, Notification: ValueChanged
2018-09-01 00:01:45.233 Detail, Node024,   Received: 0x01, 0x13, 0x00, 0x04, 0x00, 0x18, 0x0b, 0x56, 0x01, 0x60, 0x0d, 0x02, 0x01, 0x25, 0x03, 0xff, 0x2c, 0x88, 0xbf, 0x00, 0x00
2018-09-01 00:01:45.233 Detail, 
2018-09-01 00:01:45.233 Info, Node024, Received CRC16-command from node 24
2018-09-01 00:01:45.233 Info, Node024, Received a MultiChannelEncap from node 24, endpoint 2 for Command Class COMMAND_CLASS_SWITCH_BINARY
2018-09-01 00:01:45.234 Info, Node024, Received SwitchBinary report from node 24: level=On
2018-09-01 00:01:45.234 Detail, Node024, Refreshed Value: old value=false, new value=true, type=bool
2018-09-01 00:01:45.234 Detail, Node024, Changes to this value are not verified
2018-09-01 00:01:45.235 Detail, Node024, Notification: ValueChanged
2018-09-01 00:01:46.830 Detail, Node024,   Received: 0x01, 0x1a, 0x00, 0x04, 0x00, 0x18, 0x12, 0x56, 0x01, 0x60, 0x0d, 0x01, 0x01, 0x32, 0x02, 0x21, 0x34, 0x00, 0x00, 0x07, 0x32, 0x00, 0x00, 0x49, 0x78, 0xbf, 0x00, 0x4f
2018-09-01 00:01:46.830 Detail, 
2018-09-01 00:01:46.830 Info, Node024, Received CRC16-command from node 24
2018-09-01 00:01:46.830 Info, Node024, Received a MultiChannelEncap from node 24, endpoint 1 for Command Class COMMAND_CLASS_METER
2018-09-01 00:01:46.831 Detail, Node024, Refreshed Value: old value=false, new value=false, type=bool
2018-09-01 00:01:46.831 Detail, Node024, Changes to this value are not verified
2018-09-01 00:01:46.831 Info, Node024, Received Meter report from node 24: Power=184.2W
2018-09-01 00:01:46.831 Detail, Node024, Refreshed Value: old value=0.0, new value=184.2, type=decimal
2018-09-01 00:01:46.831 Detail, Node024, Changes to this value are not verified
2018-09-01 00:01:46.832 Detail, Node024, Notification: ValueChanged
2018-09-01 00:01:46.863 Detail, Node024, Notification: ValueChanged
2018-09-01 00:01:47.230 Detail, Node024,   Received: 0x01, 0x1a, 0x00, 0x04, 0x00, 0x18, 0x12, 0x56, 0x01, 0x60, 0x0d, 0x01, 0x01, 0x32, 0x02, 0xa1, 0x24, 0x00, 0x00, 0x09, 0x3c, 0x00, 0x00, 0x3a, 0xd9, 0xbf, 0x00, 0x0d
2018-09-01 00:01:47.230 Detail, 
2018-09-01 00:01:47.231 Info, Node024, Received CRC16-command from node 24
2018-09-01 00:01:47.231 Info, Node024, Received a MultiChannelEncap from node 24, endpoint 1 for Command Class COMMAND_CLASS_METER
2018-09-01 00:01:47.232 Detail, Node024, Refreshed Value: old value=false, new value=false, type=bool
2018-09-01 00:01:47.232 Detail, Node024, Changes to this value are not verified
2018-09-01 00:01:47.232 Info, Node024, Received Meter report from node 24: Voltage=236.4V
2018-09-01 00:01:47.233 Detail, Node024, Refreshed Value: old value=234.2, new value=236.4, type=decimal
2018-09-01 00:01:47.233 Detail, Node024, Changes to this value are not verified
2018-09-01 00:01:47.233 Detail, Node024, Notification: ValueChanged
2018-09-01 00:01:47.278 Detail, Node024, Notification: ValueChanged
2018-09-01 00:01:47.635 Detail, Node024,   Received: 0x01, 0x1a, 0x00, 0x04, 0x00, 0x18, 0x12, 0x56, 0x01, 0x60, 0x0d, 0x01, 0x01, 0x32, 0x02, 0xa1, 0x6c, 0x00, 0x00, 0x03, 0x48, 0x00, 0x00, 0x18, 0xfb, 0xbf, 0x00, 0x3b
2018-09-01 00:01:47.636 Detail, 
2018-09-01 00:01:47.636 Info, Node024, Received CRC16-command from node 24
2018-09-01 00:01:47.636 Info, Node024, Received a MultiChannelEncap from node 24, endpoint 1 for Command Class COMMAND_CLASS_METER
2018-09-01 00:01:47.637 Detail, Node024, Refreshed Value: old value=false, new value=false, type=bool
2018-09-01 00:01:47.637 Detail, Node024, Changes to this value are not verified
2018-09-01 00:01:47.638 Info, Node024, Received Meter report from node 24: Current=0.840A
2018-09-01 00:01:47.638 Detail, Node024, Refreshed Value: old value=0.841, new value=0.840, type=decimal
2018-09-01 00:01:47.639 Detail, Node024, Changes to this value are not verified
2018-09-01 00:01:47.639 Detail, Node024, Notification: ValueChanged
2018-09-01 00:01:47.671 Detail, Node024, Notification: ValueChanged