OpenZWave / qt-openzwave

QT5 Wrapper for OpenZWave
GNU Lesser General Public License v3.0
105 stars 30 forks source link

GE Z-Wave Motion Dimmer 26933 config parameter 8 setvalue resulting in 'Incorrect Field Type (Short) for "setvalue"' #138

Closed DanielBaulig closed 4 years ago

DanielBaulig commented 4 years ago

Setting configuration parameter 8 on GE Z-Wave Motion Dimmer 26933 fails with the following message:

2020-07-28 02:15:20.329278214  [20200728 2:15:20.328 UTC] [ozw.mqtt.commands] [debug]: Got  "OpenZWave/1/command/setvalue/"  Message:  "{\"ValueIDKey\": 2251799941349398, \"Value\": null}"
2020-07-28 02:15:20.330266679  [20200728 2:15:20.329 UTC] [ozw.mqtt.commands.setValue] [warning]: Incorrect Field Type (Short) for  "setvalue" : Value:  0
2020-07-28 02:15:20.339244437  [20200728 2:15:20.330 UTC] [ozw.mqtt.commands] [warning]: Message Processing for  "setvalue"  failed:  "{\"ValueIDKey\": 2251799941349398, \"Value\": null}"

The config value has a type of "short" in 26933-motion-dimmer-xml for config parameter 8. It seemed to have been changed from byte in https://github.com/OpenZWave/open-zwave/pull/1968 Note that at least the value range indicate that short is the correct type (assuming we are only talking about signed types).

I tried changing the value back to byte to see if that would get rid of the error, but changing the value in the xml file didn't actually change the error. I then learned that there is some kind of cache that needs updating too. I assumed it to be the ozwcache* file in the mounted docker volume and manually updated that to also use byte for the type of the config parameter 8. But that also didn't change anything. So now I'm not sure if I'm down a completely wrong path here.

Any help greatly appreciated.

tech165 commented 4 years ago

Hi, what is the value you are trying to set ? In the debug you provided it look like null or 0. Parameter 8 should be between 1 and 255. Could you make sure you are giving a value between 1 and 255 and try again ?

Thanks

DanielBaulig commented 4 years ago

I was trying to set 1 from Home Assistant Developer Tools ozw.set_config_parameter Service call with the following data:

node_id: 7
parameter: 8
value: 1

Note that for changing the type in the XML I have since figured out that I had to stop ozwdaemon first, then change the cache values and then restart ozwdaemon again. Doing it in the correct order made ozwdaemon pickup the short -> byte changes. Changing the type to byte made the 'Incorrect Field Type (Short) for "setvalue"' error disappear, but the dimmer seems to still not pickup the configuration changes.

2020-07-28 03:40:15.113928013  [20200728 3:40:15.113 UTC] [ozw.mqtt.commands] [debug]: Got  "OpenZWave/1/command/setvalue/"  Message:  "{\"ValueIDKey\": 2251799941349393, \"Value\": 1}"
2020-07-28 03:40:15.114215917  [20200728 3:40:15.114 UTC] [ozw.mqtt.commands.setValue] [info]: Setting  2251799941349393  to Value  QVariant(uint, 1)
2020-07-28 03:40:15.114381229  [20200728 3:40:15.114 UTC] [ozw.values] [debug]: setData Called for Row 36  With Value QVariant(uint, 1)
2020-07-28 03:40:15.114522708  [20200728 3:40:15.114 UTC] [ozw.values] [debug]: valueModel Changed! QTOZW_ValueIds::Value - 36 :  QVariant(uint, 1)
2020-07-28 03:40:15.114652281  [20200728 3:40:15.114 UTC] [ozw.values] [debug]: valueModel Changed! vidKey: 2251799941349393 QVariant(uint, 1)
2020-07-28 03:40:15.114850963  [20200728 3:40:15.114 UTC] [ozw.library] [info]: Info - Node: 7 Value::Set - COMMAND_CLASS_CONFIGURATION - Z-Wave Command Dim Rate - 8 - 1 - 1
2020-07-28 03:40:15.115037886  [20200728 3:40:15.114 UTC] [ozw.library] [info]: Info - Node: 7 Configuration::Set - Parameter=8, Value=1 Size=1
2020-07-28 03:40:15.115233939  [20200728 3:40:15.115 UTC] [ozw.library] [debug]: Detail - Node: 7 Queuing (Send) ConfigurationCmd_Set (Node=7): 0x01, 0x0c, 0x00, 0x13, 0x07, 0x05, 0x70, 0x04, 0x08, 0x01, 0x01, 0x25, 0x28, 0x93
2020-07-28 03:40:15.115440547  [20200728 3:40:15.115 UTC] [ozw.library] [debug]: Detail - Node: 7 Queuing (Send) ConfigurationCmd_Get (Node=7): 0x01, 0x0a, 0x00, 0x13, 0x07, 0x03, 0x70, 0x05, 0x08, 0x25, 0x29, 0x93
2020-07-28 03:40:15.115801672  [20200728 3:40:15.115 UTC] [ozw.mqtt.commands] [info]: Processed Message for  "setvalue" :  "{\"ValueIDKey\": 2251799941349393, \"Value\": 1}"
2020-07-28 03:40:15.115915726  [20200728 3:40:15.115 UTC] [ozw.library] [info]: Info - Node: 7 Sending (Send) message (Callback ID=0x28, Expected Reply=0x13) - ConfigurationCmd_Set (Node=7): 0x01, 0x0c, 0x00, 0x13, 0x07, 0x05, 0x70, 0x04, 0x08, 0x01, 0x01, 0x25, 0x28, 0x93
2020-07-28 03:40:15.116156167  [20200728 3:40:15.116 UTC] [ozw.library] [info]: Info - Node: 7 Encrypted Flag is 0
2020-07-28 03:40:15.124030184  [20200728 3:40:15.123 UTC] [ozw.library] [debug]: Detail - Node: 7   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2020-07-28 03:40:15.124264681  [20200728 3:40:15.124 UTC] [ozw.library] [debug]: Detail - Node: 7   ZW_SEND_DATA delivered to Z-Wave stack
2020-07-28 03:40:15.143834717  [20200728 3:40:15.143 UTC] [ozw.library] [debug]: Detail - Node: 7   Received: 0x01, 0x18, 0x00, 0x13, 0x28, 0x00, 0x00, 0x02, 0x00, 0xcf, 0x7f, 0x7f, 0x7f, 0x7f, 0x00, 0x00, 0x03, 0x00, 0x00, 0x00, 0x00, 0x03, 0x01, 0x00, 0x00, 0x10
2020-07-28 03:40:15.144040251  [20200728 3:40:15.143 UTC] [ozw.library] [debug]: Detail - Node: 7   ZW_SEND_DATA Request with callback ID 0x28 received (expected 0x28)
2020-07-28 03:40:15.144215748  [20200728 3:40:15.144 UTC] [ozw.library] [info]: Info - Node: 7 Request RTT 27 Average Request RTT 27
2020-07-28 03:40:15.144427060  [20200728 3:40:15.144 UTC] [ozw.library] [debug]: Detail - Node: 7 Extended TxStatus: Time: 20, Hops: 0, Rssi:  -49 --- --- --- ---, AckChannel: 0, TxChannel: 0, RouteScheme: Last Working Route, Route: 0 0 0 0, RouteSpeed: 100K, RouteTries: 1, FailedLinkFrom: 0, FailedLinkTo: 0
2020-07-28 03:40:15.144603520  [20200728 3:40:15.144 UTC] [ozw.library] [debug]: Detail - Node: 7   Expected callbackId was received
2020-07-28 03:40:15.144770259  [20200728 3:40:15.144 UTC] [ozw.library] [debug]: Detail - Node: 7   Expected reply was received
2020-07-28 03:40:15.144937423  [20200728 3:40:15.144 UTC] [ozw.library] [debug]: Detail - Node: 7   Message transaction complete
2020-07-28 03:40:15.145102273  [20200728 3:40:15.144 UTC] [ozw.library] [debug]: Detail - Node: 7 Removing current message
2020-07-28 03:40:15.145305751  [20200728 3:40:15.145 UTC] [ozw.library] [info]: Info - Node: 7 Sending (Send) message (Callback ID=0x29, Expected Reply=0x04) - ConfigurationCmd_Get (Node=7): 0x01, 0x0a, 0x00, 0x13, 0x07, 0x03, 0x70, 0x05, 0x08, 0x25, 0x29, 0x93
2020-07-28 03:40:15.145475360  [20200728 3:40:15.145 UTC] [ozw.library] [info]: Info - Node: 7 Encrypted Flag is 0
2020-07-28 03:40:15.153084714  [20200728 3:40:15.152 UTC] [ozw.library] [debug]: Detail - Node: 7   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2020-07-28 03:40:15.153275193  [20200728 3:40:15.153 UTC] [ozw.library] [debug]: Detail - Node: 7   ZW_SEND_DATA delivered to Z-Wave stack
2020-07-28 03:40:15.172884284  [20200728 3:40:15.172 UTC] [ozw.library] [debug]: Detail - Node: 7   Received: 0x01, 0x18, 0x00, 0x13, 0x29, 0x00, 0x00, 0x03, 0x00, 0xcf, 0x7f, 0x7f, 0x7f, 0x7f, 0x00, 0x00, 0x03, 0x00, 0x00, 0x00, 0x00, 0x03, 0x01, 0x00, 0x00, 0x10
2020-07-28 03:40:15.173090707  [20200728 3:40:15.172 UTC] [ozw.library] [debug]: Detail - Node: 7   ZW_SEND_DATA Request with callback ID 0x29 received (expected 0x29)
2020-07-28 03:40:15.173264112  [20200728 3:40:15.173 UTC] [ozw.library] [info]: Info - Node: 7 Request RTT 27 Average Request RTT 27
2020-07-28 03:40:15.173468905  [20200728 3:40:15.173 UTC] [ozw.library] [debug]: Detail - Node: 7 Extended TxStatus: Time: 30, Hops: 0, Rssi:  -49 --- --- --- ---, AckChannel: 0, TxChannel: 0, RouteScheme: Last Working Route, Route: 0 0 0 0, RouteSpeed: 100K, RouteTries: 1, FailedLinkFrom: 0, FailedLinkTo: 0
2020-07-28 03:40:15.173644829  [20200728 3:40:15.173 UTC] [ozw.library] [debug]: Detail - Node: 7   Expected callbackId was received
2020-07-28 03:40:15.185296125  [20200728 3:40:15.185 UTC] [ozw.library] [debug]: Detail - Node: 7   Received: 0x01, 0x0e, 0x00, 0x04, 0x00, 0x07, 0x06, 0x70, 0x06, 0x08, 0x02, 0x00, 0x03, 0xcf, 0x00, 0x44
2020-07-28 03:40:15.185496363  [20200728 3:40:15.185 UTC] [ozw.library] [info]: Info - Node: 7 Response RTT 39 Average Response RTT 39
2020-07-28 03:40:15.185675972  [20200728 3:40:15.185 UTC] [ozw.library] [debug]: Detail - Node: 7 Value Updated: old value=3, new value=3, type=byte
2020-07-28 03:40:15.185862136  [20200728 3:40:15.185 UTC] [ozw.library] [debug]: Detail - Node: 7 Changes to this value are not verified
2020-07-28 03:40:15.186039541  [20200728 3:40:15.185 UTC] [ozw.library] [info]: Info - Node: 7 Received Configuration report: Parameter=8, Value=3
2020-07-28 03:40:15.186208038  [20200728 3:40:15.186 UTC] [ozw.library] [debug]: Detail - Node: 7   Expected reply and command class was received
2020-07-28 03:40:15.186375684  [20200728 3:40:15.186 UTC] [ozw.library] [debug]: Detail - Node: 7   Message transaction complete
2020-07-28 03:40:15.186539811  [20200728 3:40:15.186 UTC] [ozw.library] [debug]: Detail - Node: 7 Removing current message
2020-07-28 03:40:15.186749068  [20200728 3:40:15.186 UTC] [ozw.library] [debug]: Detail - Node: 7 Notification: ValueRefreshed CC: COMMAND_CLASS_CONFIGURATION Instance: 1 Index: 8
2020-07-28 03:40:15.186974879  [20200728 3:40:15.186 UTC] [ozw.notifications] [debug]: Notification pvt_valueRefreshed:  2251799941349393 Thread:  0xb3cf1010
2020-07-28 03:40:15.187419669  [20200728 3:40:15.187 UTC] [ozw.mqtt.publisher] [debug]: Publishing Event valueRefreshed: 2251799941349393
kpine commented 4 years ago

The ozw integration doesn't support type "short". You should move this issue (or make a new one) to https://github.com/home-assistant/core/issues.

DanielBaulig commented 4 years ago

I don't seem to be able to transfer the issue since OZW and HA are different organizations. Will recreate it there. Thank you, @kpine!