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

mhilbush · June 22, 2018, 11:14am

Here’s the log file (reminder that this is from master version, not dev)
https://drive.google.com/open?id=1p31MNpx8AmuiPK31EfJm2Bk44P5TJgqU

And here’s what I did.

Add Node 30 from Inbox
In HABmin do Set Device as Failed on node 30
In HABmin do Remove Device From Controller on node 30
Run discovery, which detects node 30

lsiepel · June 23, 2018, 8:49pm

as a result of https://community.openhab.org/t/cant-get-the-zwave-binding-to-update-the-s2-switch-from-a-fibaro-fgd-212

Yesterday i changed from the snapshot build 1302 to this dev binding (19 june). I followd the first posts and got the network up and running in no time. I discovered something strange in habmin:

Under group associations the lifeline is empty, while it does report and work as expected.(display error?)
Associations group 4 contains two empty Associations. These associations are with full operational nodes, still work and where setup with the snapshot version. (display error?)
When an Association is removed by habmin, an NPE is shown

NullPointerException.css (8.1 KB) (css due to the forum not accepting .txt or .log ?! )

chris · June 23, 2018, 8:52pm

Yes - this is a known problem with the widget that HABmin uses so I can’t easily fix this .

The exception is thrown in ESH and not in the binding so I’m not really sure what this is without knowing what is sent over the REST interface.

lsiepel · June 23, 2018, 9:06pm

Well the NPE is possibly a result of the habmin widget problem, is point 2 also related to this ?
The REST request payload, kind of confirms this:
{group_4: [null]}
group_4
:
[null]
0
:
null

Didn’t get this problem with the snapshot version.
Maybe offtopic, but shouldn’t the REST api be protected to this kind of NPE?

chris · June 23, 2018, 9:08pm

Ok, but it’s different code right? So it can be different… I’m not really sure why the widget isn’t working, but as it doesn’t seem to be in development any more, it’s not easy to resolve.

Yes, it would be nice if it provided a nice error .

mhilbush · June 24, 2018, 12:28pm

I’ve run into my first issue with the conversion from master to dev.

My Minimotes, Wallmotes, and Fibaro Buttons won’t discover.

For example, my Wallmote thing (node 72) shows as Unknown Device in HABmin.

Normally, I would wake it up to trigger the rest of the discovery process. But, when I wake it up, I get this in the log. If a wakeup won’t trigger it to complete discovery, how can it be fully discovered?

2018-06-24 08:22:17.926 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 04 00 48 02 84 07 3A 
2018-06-24 08:22:17.927 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=72, callback=0, payload=00 48 02 84 07 
2018-06-24 08:22:17.927 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage past lock Message: class=ApplicationCommandHandler[4], type=Request[0], dest=72, callback=0, payload=00 48 02 84 07 
2018-06-24 08:22:17.927 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=72, callback=0, payload=00 48 02 84 07 
2018-06-24 08:22:17.927 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction null
2018-06-24 08:22:17.927 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 72: Application Command Request (ALIVE:PING)
2018-06-24 08:22:17.927 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 72: Incoming command class COMMAND_CLASS_WAKE_UP, endpoint 0
2018-06-24 08:22:17.928 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 72: Command class COMMAND_CLASS_WAKE_UP not found.
2018-06-24 08:22:17.928 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 72: Commands processed 1.
2018-06-24 08:22:17.928 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 72: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@2b538d1b.
2018-06-24 08:22:17.928 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2018-06-24 08:22:17.928 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2018-06-24 08:22:17.928 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

The Minimotes and Buttons exhibit the same behavior w.r.t. the WAKE_UP command class not found.

Edit: I’m also seeing this issue with my Ecolink TILTZWAVE2 garage door sensor.

chris · June 24, 2018, 1:28pm

I’ll take a look tonight…

The first part of the initialisation is to read the classes - we’ve not got that far so this is not a problem - until the device is initialised the class won’t be found…

mhilbush · June 24, 2018, 2:13pm

Thanks.

I’m using the version that is linked to in post #2952

180 │ Active   │  80 │ 2.3.0.201806161405     │ org.openhab.binding.zwave

I’m also having a problem completing discovery of my Fibaro FGK-101 Door/Window Sensor. This looks like a simple DB update, which I just made to device #847.

sihui · June 24, 2018, 2:45pm

~~#381~~ #847

mhilbush · June 24, 2018, 2:57pm

Yes, thanks for the correction!

mhilbush · June 24, 2018, 3:38pm

So, to summarize, all my mains and battery-powered devices appear to have migrated successfully, except for the following devices:

Aeon DSA03202 Minimote
Aeon ZW130 Wallmote
Fibaro FGPB-101 Button
Ecolink TILTZWAVE2 Garage Door Sensor
Fibaro FGK-101 Door/Window Sensor

The FGK-101 is just a database issue, which I’ve already fixed.

The remaining 4 devices appear to have the same characteristic that they all have a wakeup interval of 0 by default. Not sure if this is relevant. I vaguely recall a change a while back to specifically account for these types of devices during initialization. Again, not sure if this is relevant.

As an aside, I’d like to see these log messages moved to TRACE level. With a big network, it generates a lot of noise in the logs…

2018-06-24 11:19:32.863 [DEBUG] [nhab.binding.zwave.discovery.ZWaveDiscoveryService] - NODE XX: Checking zwave:xxxxxxxxxxxxx
...

chris · June 24, 2018, 4:25pm

Thanks for investigating and finding this commonality - I’ll see if I can see any issue here…

Done.

mhilbush · June 24, 2018, 4:27pm

Was this the change to deal with devices that don’t wake up?

chris · June 24, 2018, 4:35pm

Yes, I already had a quick look at this and I don’t think it’s relevant as it’s related to the FAILED check and I think this code is now gone with the change in how this works… I need to double check though as I don’t currently have this code loaded.

chris · June 24, 2018, 5:12pm

This code is still in play, but it clearly went past this as this code would set the state to DONE if it was already initialised, and from your log, we’re in state PING which is after FAILED_CHECK, and clearly before DONE…

chris · June 24, 2018, 5:13pm

Do you have a longer log of the initialisation? I’f like to see what’s happening before it gets into this state…

mhilbush · June 24, 2018, 5:14pm

No but I’ll create one.

chris · June 24, 2018, 5:14pm

Thanks. Ping it over by email if you like…

mhilbush · June 24, 2018, 5:24pm

Starting at 2018-06-24 13:14:58.382

deleted the thing for node 72
ran discovery
added node 72 from inbox

https://drive.google.com/open?id=1p31MNpx8AmuiPK31EfJm2Bk44P5TJgqU

mhilbush · June 25, 2018, 12:36pm

One other data point…

I excluded one of the Minimotes, did a factory reset, then included it into the network. Appears to have the same behavior as above. It’s node 93 in this log.
https://drive.google.com/open?id=17wZy49pAO59SmPpO-kz9IF3d2tyzJr8I