OH2 Z-Wave refactoring and testing... and SECURITY

big thanks to you chris for your time you spend with my problem ! enough for today :wink:
If I find something out, why the FGDW-002 does not work every now and then, IĀ“ll will tell.

strange it is just that it works with the standard zwave binding to 99%ā€¦

Hi there!

tldr; When setting two zwave items to same state, openhab sometimes will see one node being updated and reverted back to starting state. When this happens, SWITCH_BINARY_GET is sent to node before SWITCH_BINARY_SET. Issue is hard to reproduce with debug logs.

Thank you for your hardwork on this plugin, it works great! Butā€¦ I do experience one painfull issue with itemā€™s state updates. Sorry if this is a duplicate but this thread is so painfull to search.

I have a setup where a change in Node 24 (binary sensor), should trigger change to same state in Node 30 and Node 31. All nodes are Neo Coolcam, 24 is motion sensor and 30 & 31 are Light Switch EU 2CH.

Rules are simple turn both on when sensor says so and turn the other one, when one of nodes is locally changed. Iā€™m having an issues with second part, from openhabā€™s logs it look like after both items are set to state indicated by sensor, one of the them is set back to previous state - even when node it self has changed to new state and I do see light :wink: This of course triggers second part of rules and switches the other node back to starting state. In the end, openhab thinks that both nodes are in the same state (and equal to starting state), where in fact they are not.

Iā€™ve tried to track a little bit what is going but it seems your development branch on github is not up-to-date with your releases here. What I found is that, after sending command to item, openhab marks item state to new one, being requested, then for some reason a zwave controller sends to offending node SWITCH_BINARY_GET before SWITCH_BINARY_SET. So once GETā€™s response is received openhab will mark item back to previous state - triggering rules updates. SWITCH_BINARY_SET is sent properly, and node switches itself, but openhab is not notified.

You can find logs here, one when all went fine, with debug on zwave and trace on transaction manager. And second one with only debug but the order of messages is wrong. It looks like the number of logs is impacting this issue occurance or not. I was unable to reproduce it with TRACE on zwave transaction manager. And even with DEBUG it will sometimes not reproduce, but when Iā€™m on INFO it will usually work in wrong way.


I do suspect that a bug is in ZWaveTransactionManager, somehow transaction identifiers are shown out of order when SWITCH_BINARY_GET is sent before SWITCH_BINARY_SET. It looks like, either queue is storing them in wrong order, or they are grabbed in wrong order from it (getMessageFromQueue() can do this if node is not awake during iteration and becomes awake midthru). I was never able to reproduce it with only single node.

P.S. Unfortunately Iā€™m unable to bind 30 and 31 thru associations (they do sometimes work but most often not - same thing on non openhab so probably issue on switches), and Iā€™m forced to use openhab to keep both nodes in sync.

This shouldnā€™t be possible as the queue has a priority system, and SET is a higher priority than GET. There was a problem with the priority under some circumstances, but this was fixed a few weeks ago and is included in the latest development version here.

I think the latest source is available on GH, but it is not merged yet. You need to look at the open PR.

No - itā€™s an issue with the queue.

Transaction IDs are not meant to be sent in order, so this is not a problem.

Please use the latest version that I post here and it should solve this issue.

Ah sorry, I must have missed open PR! Anyway, I would not write here having not checked latest version :wink:
Those logs which I send, where from 17th July. And here you have debug from latest version (24th of July) - the same issue. SET is send after GET.

openhab> bundle:list | grep -i zwave
225 ā”‚ Active   ā”‚  80 ā”‚ 2.4.0.201807242215     ā”‚ ZWave Binding

I did complete restart of docker container before testing.

Iā€™ve updated the binding to add another debug message. Please can you provide the log with this binding.

I also added some more tests, and they do seem to show that the queue prioritisation is correct.

The GET that is being sent should not actually be there anyway, but I will fix that after we resolve the queue issue.

Sure, Iā€™ve added new log log_bad_07_29.txt ->cloud.zlomek.net.pl/index.php/s/GCjMMtn2Kx3cfHm/download?path=%2F&files=log_bad_07_29.txt (Iā€™m getting an error trying to post it as an link, sorry - please add https before url)

It works sometimes, so I would rather think it is some timing/synchronization issue rather than constant error, especially since once Iā€™m turning on TRACE on transaction manager, I can not reproduce this thing.

Arghā€¦ previous posts got flagged as advertisement (seriouslyā€¦) let me know if last one works, if not I will try to post logs somewhere else.

I lost track of whatā€™s in the latest dev binding in post #1. Are any of the database changes from this past week in that build?

It has the holdoff stuff mainly, but there are a few other small changes as well.

Yes - the database is up to date as of this morning. I am generally keeping this up to date whenever I create a JAR.

1 Like

It wasnā€™t advertisement - it came up as spam as you posted multiple links to the same address. Iā€™ve unflagged them (sorry).

Ok, Iā€™ve just realised that when iterating over a priority queue, the queue iterator doesnā€™t respect the priority order! This probably explains the issue, but is a pain to fix :frowning: .

I will remove the GET since it should not be here now - the GET is managed differently via the general repoll mechanism. Removing it will therefore likely solve your problem until I can work out a way to use a priority queue that, well, respects the priority!

Oh myā€¦ They do have strange ideas in Java :wink: Iā€™m glad you found it.

It seems you do need priority iterators only to filter out pending transactions to sleeping nodes. Maybe separate list (anything sortable) of transaction for those?

Yes - this is also my thought. Itā€™s a bit of a multi-dimensional problem though - I did try multiple lists in the past, but this causes other problems in that you then need to ensure that over all lists there is some sort of ordering to prevent one node (or a few nodes) from hogging the systemā€¦

Some thought required :wink: .

By the way - the binding is updated so hopefully it will at least solve the problem you have.

You are the boss :wink:

Iā€™ve checked latest update and yes, without GET my use case seems to be working. Correct me if Iā€™m wrong - without GET disabling auto update on item will result in state of item getting stuck until node will send a report, right? Or is the binding updating state after ACK is received?

Anyway, bonus ā€˜thank youā€™ - a delay is slightly lower now :wink:

The system normally updates the state when the command is issued - I think this is the norm unless you have disabled this (and I forget how to disable it). I think you had disabled the GET - I noticed the repoll period was set quite high - the default is 1500ms. If you want to have the GET requests again, then you should set the repoll period to something lower (a few hundred milliseconds is probably good).

Yes, I was experimenting until Iā€™ve found those GETs being sent prematurely. Anyway, thank you for help :slight_smile:

Hi. Iā€™m using a Fibaro Dimmer 2 FGD-212 with firmware 3.5, and I was seeing some odd behaviour with version 2.3 of the binding. Iā€™ve upgraded to the latest snapshot 2.4.0.201807291853, and now Iā€™m seeing different odd behaviour!

With the old version, if I turned the dimmer on via the toggle switch in the OpenHab UI, it would show a brightness of 100% regardless of the fact that the dimmer was set to turn on at its previous brightness and often wasnā€™t running at 100%. I thought this might be related to the GET/SET issue above, so I upgradedā€¦

Now when I turn on via the toggle, the brightness in the UI jumps to 100% and then back to the correct value. However, there are other issues. The power reports donā€™t seem to update reliably when they did before. Oddly, they seem to lag one change behind sometimes - i.e. if I put the power to 100% (with a single 50W halogen bulb attached), the power readout will be arbitrary. But then if I dim it to 50%, the power readout will change a second later to approx 50W (i.e. the power before the change). Then if I dim it again, the power readout will change to, say, 20W. i.e. the power readout often seems to be accurate for the dimmer level prior to the last change!

Separately, I have a TKB TZ69 wall socket on/off switch, and the power readouts from that seem to have disappeared completely which is a shame because I used them a lot and they included current and power factor.

Iā€™ll get you some debug logs shortlyā€¦

1 Like

I had this EXACT same issue with my dimmers and your power usage. I basically gave up on it as I couldnt work out what the problem was.

If the Thing doesnā€™t show all of the configuration parameters from the device db, or if you never did this when first upgrading to the development version of the binding, delete and rediscover the Thing. This device has options for configuring when the power reports are sent. Also chack the associations, since you may just be getting readings after it receives a command and gets polled.

Same. Sounds like associations got lost at some point.

I cannot get the addon to work. I did like this (descriped further down in the post):

Delete all Zwave Things from Habmin.
Uninstall the Zwave binding from Habmin. - You will NOT reinstall it.
Stop OH2
Copy the JAR file to your /usr/share/openhab2/addons folder.
Start OH2.
log into Karaf ieā€¦ ssh openhab@localhost -p 8101 password is habopen
Start the zwave binding with: bundle:start org.openhab.binding.zwave
If get an error, you need to install the serial binding first: feature:install openhab-transport-serial
Now got back to Habmin, and Readd a Zwave Controller. Do NOT re-install the 2.0 Zwave Binding.
Set your USB port and rescan for devices.

But my Z-wave controller (Razberry) just says initializing and nothing more happens ??