Z-Wave: Polling deferred until initialisation complete

Add-ons Bindings
1

I’m hoping someone can point me in the right direction with this one please. Fairly new to OpenHAB and certainly new to Z Wave. Bad combo I fear :slight_smile:
So I’m on Openhab 2.4.0-SNAPSHOT, build #1369. I’m running this on a Raspberry PI 3. Vanilla Raspbian install with latest updates.

I got a Aeotec Z-Wave Stick. Connected fine and added as a “Thing”. The issue comes when adding an Aeotec smart switch (https://aeotec.com/z-wave-plug-in-switch), which is my first and only Z-Wave item.

I can discover it fine in OpenHAB. I can interact with it in such that sending an on/off command OpenHAB works. But - except for one time only - I am not able to get any “actual” information back from the device so I can’t see energy usage (fair enough) but more importantly I can’t see whether it’s currently on or off (bad).

I removed the “thing” and added it again, whilst capturing a DEBUG log. It looks like it’s discovered and added and initialized fine. But I see no values updating. And hwen I send a manual refresh this happens:

2018-10-24 17:59:24.220 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Command received zwave:device:512:node2:meter_watts --> REFRESH
2018-10-24 17:59:24.237 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Polling intialised at 1800 seconds - start in 50 milliseconds.
2018-10-24 17:59:24.287 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Polling…
2018-10-24 17:59:24.291 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Polling deferred until initialisation complete

I have put the entire log file here:

I would be extremely grateful if anybody might be able to look at this please and potentially point me in the right direction?

Many thanks in advance

Martin

2

This simply means that the device is not initialised, and until the initialisation is complete, it won’t perform the polling.

There’s next to nothing in the log, so I can’t comment much more - there is no communication at all between the device and the controller, so maybe you should exclude the device and re-include it in case there was an issue with the controller during inclusion.

3

Thank you very much Chris, much appreciated. I guess I may be misreading the log then?

From this entry:

2018-10-24 17:57:38.843 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Device initialisation complete.

I had assumed that the initialisation does complete successfully. And shouldn’t the fact that I can send on / off commands also mean that it is initialised or is that a red herring?

I also see this in the log:

2018-10-24 17:57:49.888 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=195, payload=C3 06 02 00

which I took to mean that it had received a message.

I just don’t understand enough to see from the log why it drops out from initialised to not fully initialised?

Thanks for any input

Martin

4

It’s very hard to know what is happening. As I said, there’s very little in the log and it only lasts about 2 seconds. There is no communications with the device, and I don’t really know what state anything is in.

Possibly this is true, but not necessarily. But here you have more information than me as the log doesn’t have any of this either.

Yes, there is a message received here, but this message comes from the controller, not the device itself.

The log looks like this in simpler terms -:

image
image1304×412 70.3 KB

The only messages in here are “AddNodeToNetwork” messages which are only between the controller and the binding and do not involve the device.

5

Aaah right, ok. Apologies. I did not realize that this was only messages between the controller and binding, rather than the device itself.

Randomly (at least to me), without me touching anything it appears to have started working. I have added a new log file to dropbox (zwave1.log) that shows that while at

2018-10-24 18:31:53.762 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Polling deferred until initialisation complete

it then starts polling successfully

2018-10-24 18:35:21.741 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Polling intialised at 1800 seconds - start in 1500 milliseconds.

Since these are brand new devices - is it just a question of allowing enough time for the network to “settle”? It certainly looks like it’s working now!

Many thanks for looking into this and your comments.

On a side note, what tool do you use to display the log files as in the screenshot above? (edit: never mind, I found this: https://www.cd-jackson.com/index.php/openhab/zwave-log-viewer)