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

Here are the minor problems that I have identified in my system while using the latest refactored Z-Wave binding
OH 2.2.0 Snapshot 976 with 2.1.0.201706302351 org.openhab.binding.zwave

i) Aeotec Z-Stick Gen5 ZW090-C (1 unit)
All ok

i) Aeotec Sensor ZW100 (1 unit)
Battery level reported at 1%
Not using sec inclusion for now (for testing purposes)
NODE 8: Is currently marked as failed by the controller! (every 30 secs) but working and reporting values normally

ii) Fibaro Sensor FGMS-001 (2 units)
All ok

iii) Fibaro Button FGPB-001 (2 units)
Battery level reported at 1%

iv) Fibaro Dimmer FGD-212 (1 unit)
All ok

v) Other issues (related to UIs, not the binding)
Several small problems when trying to change config parameters using PaperUI (I am getting usually error 500)
Some small problems when using HABmin to change config parameters for some devices (null exceptions)
I will capture debug logs and post more info soon

In general: It’s working fine and these small issues don’t bother me :slight_smile:

I don’t think this is directly related to the zwave binding. It’s saying it can’t start because it’s missing some other bundles. I guess maybe something didn’t install cleanly following the update?

Here are two more NPEs from the console that came up after an exclusion and inclusion, respectively:

Exception in thread "Timer-23" java.lang.NullPointerException
        at org.openhab.binding.zwave.internal.protocol.ZWaveNode$WakeupTimerTask.run(ZWaveNode.java:1407)
        at java.util.TimerThread.mainLoop(Timer.java:555)
        at java.util.TimerThread.run(Timer.java:505)
Exception in thread "Thread-43" java.lang.IllegalArgumentException: Illegal status REMOVED. The thing was in state ONLINE and not in REMOVING
        at org.eclipse.smarthome.core.thing.internal.ThingManager$1.ensureValidStatus(ThingManager.java:186)
        at org.eclipse.smarthome.core.thing.internal.ThingManager$1.statusUpdated(ThingManager.java:151)
        at org.eclipse.smarthome.core.thing.binding.BaseThingHandler.updateStatus(BaseThingHandler.java:386)
        at org.eclipse.smarthome.core.thing.binding.BaseThingHandler.updateStatus(BaseThingHandler.java:415)
        at org.openhab.binding.zwave.handler.ZWaveThingHandler.ZWaveIncomingEvent(ZWaveThingHandler.java:1343)
        at org.openhab.binding.zwave.internal.protocol.ZWaveController.notifyEventListeners(ZWaveController.java:549)
        at org.openhab.binding.zwave.internal.protocol.serialmessage.RemoveFailedNodeMessageClass.handleRequest(RemoveFailedNodeMessageClass.java:140)
        at org.openhab.binding.zwave.internal.protocol.ZWaveController.handleIncomingRequestMessage(ZWaveController.java:228)
        at org.openhab.binding.zwave.internal.protocol.ZWaveController.handleIncomingMessage(ZWaveController.java:196)
        at org.openhab.binding.zwave.internal.protocol.ZWaveTransactionManager$ZWaveReceiveThread.run(ZWaveTransactionManager.java:546)

.

Exception in thread "Timer-80" java.lang.NullPointerException
        at org.openhab.binding.zwave.internal.protocol.ZWaveNode$WakeupTimerTask.run(ZWaveNode.java:1407)
        at java.util.TimerThread.mainLoop(Timer.java:555)
        at java.util.TimerThread.run(Timer.java:505)
Exception in thread "Thread-44" java.lang.NullPointerException
        at org.openhab.binding.zwave.internal.protocol.serialmessage.AddNodeMessageClass.handleRequest(AddNodeMessageClass.java:154)
        at org.openhab.binding.zwave.internal.protocol.ZWaveController.handleIncomingRequestMessage(ZWaveController.java:228)
        at org.openhab.binding.zwave.internal.protocol.ZWaveController.handleIncomingMessage(ZWaveController.java:196)
        at org.openhab.binding.zwave.internal.protocol.ZWaveTransactionManager$ZWaveReceiveThread.run(ZWaveTransactionManager.java:546)

The device I was trying to re-include popped back up in the inbox with the same ID. After adding, it’s marked in red as not communicating with the controller, and the log just loops. Probably a ghost:

2017-07-01 03:21:49.922 [IsFailedNodeMessageClass  ] - NODE 32: Requesting IsFailedNode status from controller.
2017-07-01 03:21:49.968 [IsFailedNodeMessageClass  ] - NODE 32: Is currently marked as failed by the controller!
2017-07-01 03:21:49.974 [ZWaveNodeInitStageAdvancer] - NODE 32: Node Init response (0) COMPLETE
2017-07-01 03:21:49.974 [ZWaveNodeInitStageAdvancer] - NODE 32: Node Init transaction completed with response COMPLETE
2017-07-01 03:22:19.979 [IsFailedNodeMessageClass  ] - NODE 32: Requesting IsFailedNode status from controller.
2017-07-01 03:22:20.051 [IsFailedNodeMessageClass  ] - NODE 32: Is currently marked as failed by the controller!
2017-07-01 03:22:20.054 [ZWaveNodeInitStageAdvancer] - NODE 32: Node Init response (0) COMPLETE
2017-07-01 03:22:20.054 [ZWaveNodeInitStageAdvancer] - NODE 32: Node Init transaction completed with response COMPLETE

The device is a Leviton VRMX1 dimmer which was stuck initializing (Request_NIF) even after OH restarts, which shouldn’t be possible. I vote for Reinitialize to be available even if the device hasn’t initialized. Hopefully that would just be a UI change in Habmin

This is another change in ESH! It’s now not possible to remove devices from the binding - you’ll need to delete it manually. I’ll remove this code from the binding.

Why would this help? If the device initialisation isn’t working, then I’m unsure why restarting it will help. If it’s not responding to the Request NIF, then reinitialising won’t help as this is nearly the first thing initialisation does anyway.

hey @chris , did you manage to look at ticket d4n73B28PgT regarding warm white not functioning in zipato rgbw bulb in the development binding?
Do you need more logs?
Wife does not like the dentist feeling in there at the moment :wink:

quick question @chris:
State values of battery levels are reported as:

openhab> items list |grep -i battery
FibEye01_Bat (Type=NumberItem, State=0.92000000, Label=FE01 Battery, Category=battery, Groups=[gZWave])
FibEye02_Bat (Type=NumberItem, State=0.74000000, Label=FE02 Battery:, Category=battery, Groups=[gZWave])
FibBut01_Bat (Type=NumberItem, State=1.00000000, Label=FB01 Battery:, Category=battery, Groups=[gZWave])
FibBut02_Bat (Type=NumberItem, State=1.00000000, Label=FB02 Battery:, Category=battery, Groups=[gZWave])
MSens601_Bat (Type=NumberItem, State=1.00000000, Label=MS01 Battery:, Category=battery, Groups=[gZWave])

as a result, when formatting the items with %d (this is how I used to have them with the previous binding):

Number FibEye01_Bat "FE01 Battery [%d %%]" <battery> (gZWave) channel="zwave:device:ZW090C:node2:battery-level"}

and sitemap:

Text    item=FibEye01_Bat

I get (when refreshing my basicui)

017-07-01 11:11:40.329 [WARN ] [ui.internal.items.ItemUIRegistryImpl] - Exception while formatting value '0.92000000' of item FibEye01_Bat with format '%d %%': java.util.IllegalFormatConversionException: d != java.math.BigDecimal

When I switch to %s or %.0f %% the error goes away but I have the following result (left uses %s, right uses %.0f)

Is this related to the binding and the way it stores the state values in the items or I am just fooking up something else? :slight_smile:

Ps: Most possibly, I will need to use a x-formation

I need to look at why the battery seems to be causing people problems. This is a percent type, and in my tests it is correctly reporting the percentage so I need to look at this more.

1 Like

on a related note (from the Aeotec Multisensor ZW100), the relative humidity is being stored as a whole number (state value of 44) (not decimal 0.44) and this works fine:

openhab> items list |grep -i humidity
MSens601_Humidity (Type=NumberItem, State=44, Label=MS01 Humidity:, Category=humidity, Groups=[gZWave])

items:

Number  MSens601_Humidity       "MS01 Humidity: [%.0f %%]"      <humidity>      (gZWave)        {channel="zwave:device:ZW090C:node8:sensor_relhumidity"}

sitemap:

Text item=MSens601_Humidity

basicui result:

Could you please provide more info?

I occasionally have mains powered devices that are stuck in a heal, or in some initialization state. I just delete, they reinit and come right back up. Sometimes battery powered devices, but them you have to wake them up several times. It’s just an occasional maintenance routine. It seems as though there’s a timeout or something that’s hung them up, and they just need a jump start. Deleting means having to go through inclusion to get them back, which slows everything down. Sometimes I just restart if there’s a number of them hung up. The reinit option would be faster. And I thought (could be wrong) you mentioned a possibility of unhiding it in one of your posts. So I thought I’d bring it up. Why is it hidden? Was it available in OH1? Wow… I’m forgetting OH1 stuff already!

A somewhat related topic is to provide the option of disabling the reinit on startup, similar to what was done for nightly heals. I can’t see the need or benefit for the devices to be initialized so often. Although, I restart more frequently than most. I guess if it was really important to me I’d submit a PR and get into the code :thinking:.

Just delete the thing. Basically, the binding can exclude the device, but it now can’t remove the thing - hence this error. So from the ZWave size, the device should have been removed from the controller ok but on the OH side, the thing is still there.

Why are they “stuck”? Starting the init again will just mean it takes longer to initialise. If they really are “stuck” then they will be stuck again when they get back to that point next time.

Again, if you start the init again, you have to wake them up even more than if you leave it alone - right?

I don’t really understand why you would do this, but up to you ;).

Not that I remember. If the device is in initialisation state, then it doesn’t show this option.

I don’t think this option was available in OH1 at all (but like you, I’ve forgotten OH1 :slight_smile: ).

Hmmm :confused:. There is no reinit on startup. The binding saves all the information it needs into the XML file so it doesn’t need to do this. All it does on startup is to read the dynamic states in case something has changed so that the item states are consistent. It will only do a reinitialisation if the XML file is corrupted or missing.

Since switching to the 2.1-snapshot I am experiencing network instabilities. I have an AEON LABS controller and qubino flush shutters ZMNHCD and 2 relays ZMNHBD. The symptoms are that nodes are frequently going into:

2017-07-01 14:01:35.212 [WARN ] [rialmessage.IsFailedNodeMessageClass] - NODE 36: Is currently marked as failed by the controller!

before they are marked as “fail check”. It is as subset of nodes for which this is happening, some are rotating between “failed” and “online”, one node stays in failed, power on/off of the node did not recover it. I never saw this with OH2.0 versions of the binding. Any idea how to further diagnose this problem ?

Please read (search) further in this thread for more information. This is a response from the controller and I will change the way this works at some point.

So, just trying this out of the first time, and one of my nodes (an FGS222 Double Relay Switch) shows as being online, but all commands fail with a “no messages returned from converter” error:

 2017-07-01 16:03:36.487 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Command received zwave:device:zstick:node29:switch_binary1 --> ON
 2017-07-01 16:03:36.487 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: No messages returned from converter

Is there an easy fix for this?

Dan

Did you follow the instructions and delete all things, or did you just cop over the JAR and restart? My guess is you haven’t deleted everything?

was careful to delete everything first, but just in case I slipped up, I’ll try deleting that device and re-adding it

OK - just tried that but get the same error

(really appreciate you responding so quickly, by the way)

I guess the next question then is have all the devices initialised ok? Is there an XML generated? After that I’d probably need to see a log and some concrete example otherwise it’s just guessing :frowning: .

All the devices initialised fine, including the troublesome node (but excluding some battery-powered devices, which I’ll presumably need to wake a few times).

XML file was generated - see here

logs from the point I re-added the node are here

Anything else I should post?

I’ve just updated the binding on my site to add 1 line of debug. If you try an on.off switch again let’s see what this shows. I think it will now log a “command class not found” error. The next question will be why, and to that I’m not really sure, but let’s confirm the log first…

yup:

2017-07-01 16:42:05.579 [DEBUG] [converter.ZWaveBinarySwitchConverter] - NODE 29: Command class class COMMAND_CLASS_SWITCH_BINARY for endpoint 1 not found

weird!