My test results with z-wave 2.4 snapshot 20181124

HomeAutomation · November 24, 2018, 2:53pm

I want to share my test results with the new z-wave binding:

I come from OH 2.3 stable, but I think most of my z-wave configs are with z-wave binding 2.2 stable. I run into a problem with z-wave 2.3 yesterday, so I decided to upgrade to lastest OH 2.4 snapshot and z-wave biding. Here are my results with my devices. I will continue if I get all my devices online again.

AEOTEC ZW112 door/window: work as before, no impact
Eurotronic Spirit radiator thermostat: works as before, no impact
Fibaro RGBW controller: works as before, no impact
Z-Wave WALLC-S Wall switch: works as before, no impact

Fibaro FGR222 roller shutter: works different as before
First, most of my settings are gone, I had to set them again. But what the bad thing is now. that the rollershutter reports position status not even if stops. It sends the position while running. This breaks some of my rules. I use autoupdate=false to get a position value only from rollershutter by itself. But the behaviour is different now. If I click on a button or send a command by OH the rolleshutter works but send me the position while running. With old binding I only got a new position value if the rollershutter stops running. Can anyone verify this?

POPP Rain-sensor 700168: Gives error message:

2018-11-24 15:57:07.547 [ERROR] [nal.common.AbstractInvocationHandler] - An error occurred while calling method 'ThingHandler.initialize()' on 'org.openhab.binding.zwave.handler.ZWaveThingHandler@ce735': 1
java.lang.ArrayIndexOutOfBoundsException: 1
        at org.openhab.binding.zwave.handler.ZWaveThingHandler.initialiseNode(ZWaveThingHandler.java:226) ~[?:?]
        at org.openhab.binding.zwave.handler.ZWaveThingHandler.bridgeStatusChanged(ZWaveThingHandler.java:512) ~[?:?]
        at org.openhab.binding.zwave.handler.ZWaveThingHandler.initialize(ZWaveThingHandler.java:164) ~[?:?]
        at sun.reflect.GeneratedMethodAccessor248.invoke(Unknown Source) ~[?:?]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
        at java.lang.reflect.Method.invoke(Method.java:498) ~[?:?]
        at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:153) [101:org.eclipse.smarthome.core:0.10.0.201811171951]
        at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:53) [101:org.eclipse.smarthome.core:0.10.0.201811171951]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
        at java.lang.Thread.run(Thread.java:748) [?:?]
2018-11-24 15:57:07.562 [ERROR] [core.thing.internal.ThingManagerImpl] - Exception occurred while initializing handler of thing 'zwave:device:15a7a49f3a6:node14': 1
java.lang.ArrayIndexOutOfBoundsException: 1
        at org.openhab.binding.zwave.handler.ZWaveThingHandler.initialiseNode(ZWaveThingHandler.java:226) ~[?:?]
        at org.openhab.binding.zwave.handler.ZWaveThingHandler.bridgeStatusChanged(ZWaveThingHandler.java:512) ~[?:?]
        at org.openhab.binding.zwave.handler.ZWaveThingHandler.initialize(ZWaveThingHandler.java:164) ~[?:?]
        at sun.reflect.GeneratedMethodAccessor248.invoke(Unknown Source) ~[?:?]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
        at java.lang.reflect.Method.invoke(Method.java:498) ~[?:?]
        at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:153) [101:org.eclipse.smarthome.core:0.10.0.201811171951]
        at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:53) [101:org.eclipse.smarthome.core:0.10.0.201811171951]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
        at java.lang.Thread.run(Thread.java:748) [?:?]
2018-11-24 15:59:31.466 [INFO ] [ommandclass.ZWaveVersionCommandClass] - NODE 13: Command Class COMMAND_CLASS_BASIC has version 0!
2018-11-24 15:59:32.468 [WARN ] [re.thing.internal.ThingFactoryHelper] - Could not create channel 'basic_basic_number' for thing type 'zwave:device:15a7a49f3a6:node13', because channel type 'zwave:basic_number' could not be found.

HomeAutomation · November 24, 2018, 2:58pm

If I send a reinitialize to any device I get:

2018-11-24 15:57:07.547 [ERROR] [nal.common.AbstractInvocationHandler] - An error occurred while calling method 'ThingHandler.initialize()' on 'org.openhab.binding.zwave.handler.ZWaveThingHandler@ce735': 1
java.lang.ArrayIndexOutOfBoundsException: 1
        at org.openhab.binding.zwave.handler.ZWaveThingHandler.initialiseNode(ZWaveThingHandler.java:226) ~[?:?]
        at org.openhab.binding.zwave.handler.ZWaveThingHandler.bridgeStatusChanged(ZWaveThingHandler.java:512) ~[?:?]
        at org.openhab.binding.zwave.handler.ZWaveThingHandler.initialize(ZWaveThingHandler.java:164) ~[?:?]
        at sun.reflect.GeneratedMethodAccessor248.invoke(Unknown Source) ~[?:?]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
        at java.lang.reflect.Method.invoke(Method.java:498) ~[?:?]
        at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:153) [101:org.eclipse.smarthome.core:0.10.0.201811171951]
        at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:53) [101:org.eclipse.smarthome.core:0.10.0.201811171951]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
        at java.lang.Thread.run(Thread.java:748) [?:?]
2018-11-24 15:57:07.562 [ERROR] [core.thing.internal.ThingManagerImpl] - Exception occurred while initializing handler of thing 'zwave:device:15a7a49f3a6:node14': 1
java.lang.ArrayIndexOutOfBoundsException: 1
        at org.openhab.binding.zwave.handler.ZWaveThingHandler.initialiseNode(ZWaveThingHandler.java:226) ~[?:?]
        at org.openhab.binding.zwave.handler.ZWaveThingHandler.bridgeStatusChanged(ZWaveThingHandler.java:512) ~[?:?]
        at org.openhab.binding.zwave.handler.ZWaveThingHandler.initialize(ZWaveThingHandler.java:164) ~[?:?]
        at sun.reflect.GeneratedMethodAccessor248.invoke(Unknown Source) ~[?:?]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
        at java.lang.reflect.Method.invoke(Method.java:498) ~[?:?]
        at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:153) [101:org.eclipse.smarthome.core:0.10.0.201811171951]
        at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:53) [101:org.eclipse.smarthome.core:0.10.0.201811171951]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
        at java.lang.Thread.run(Thread.java:748) [?:?]

HomeAutomation · November 24, 2018, 3:16pm

Device Fibaro FGK - 101 Firmware 2.5 gives me this error:

2018-11-24 16:13:46.400 [ERROR] [nal.common.AbstractInvocationHandler] - An error occurred while calling method 'ThingHandler.initialize()' on 'org.openhab.binding.zwave.handler.ZWaveThingHandler@1944548': 1
java.lang.ArrayIndexOutOfBoundsException: 1
        at org.openhab.binding.zwave.handler.ZWaveThingHandler.initialiseNode(ZWaveThingHandler.java:226) ~[?:?]
        at org.openhab.binding.zwave.handler.ZWaveThingHandler.bridgeStatusChanged(ZWaveThingHandler.java:512) ~[?:?]
        at org.openhab.binding.zwave.handler.ZWaveThingHandler.initialize(ZWaveThingHandler.java:164) ~[?:?]
        at sun.reflect.GeneratedMethodAccessor248.invoke(Unknown Source) ~[?:?]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
        at java.lang.reflect.Method.invoke(Method.java:498) ~[?:?]
        at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:153) [101:org.eclipse.smarthome.core:0.10.0.201811171951]
        at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:53) [101:org.eclipse.smarthome.core:0.10.0.201811171951]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
        at java.lang.Thread.run(Thread.java:748) [?:?]
2018-11-24 16:13:46.408 [ERROR] [core.thing.internal.ThingManagerImpl] - Exception occurred while initializing handler of thing 'zwave:device:15a7a49f3a6:node15': 1
java.lang.ArrayIndexOutOfBoundsException: 1
        at org.openhab.binding.zwave.handler.ZWaveThingHandler.initialiseNode(ZWaveThingHandler.java:226) ~[?:?]
        at org.openhab.binding.zwave.handler.ZWaveThingHandler.bridgeStatusChanged(ZWaveThingHandler.java:512) ~[?:?]
        at org.openhab.binding.zwave.handler.ZWaveThingHandler.initialize(ZWaveThingHandler.java:164) ~[?:?]
        at sun.reflect.GeneratedMethodAccessor248.invoke(Unknown Source) ~[?:?]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
        at java.lang.reflect.Method.invoke(Method.java:498) ~[?:?]
        at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:153) [101:org.eclipse.smarthome.core:0.10.0.201811171951]
        at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:53) [101:org.eclipse.smarthome.core:0.10.0.201811171951]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
        at java.lang.Thread.run(Thread.java:748) [?:?]
2018-11-24 16:15:01.998 [WARN ] [ndclass.ZWaveAlarmSensorCommandClass] - NODE 42: Detected Fibaro FGK - 101 Door / Window sensor, only requesting alarm type Smoke.

chris · November 24, 2018, 3:52pm

Please provide a debug log that shows your problem and I will try and take a look.

HomeAutomation · November 24, 2018, 5:39pm

Rollershutter 	RS_RollerShutter_01		"Rollo Computerzimmer [(%d)]"			(gMAPDB){ channel="zwave:device:xxxx:node4:blinds_control",autoupdate="false"}

Here is the log of the rollershutter NODE004:

This one by manually push the physical attached switch (works correct)
rollershutter manually click on switch.txt (8.5 KB)

This one by using the item, works wrong now
rollershutter click on item.txt (28 KB)

The problem is this. I just click one time on the OH rollershutter item to go up. But it sends 31 in the middle of the way up and at the end if it stopps 100. I expect RS_RollerShutter_01 changed from 27 to 100 (start position and end position. 31 is somewhere in the middle and not interested in.

2018-11-24 18:28:26.818 [ome.event.ItemCommandEvent] - Item 'RS_RollerShutter_01' received command UP
2018-11-24 18:28:28.407 [vent.ItemStateChangedEvent] - RS_RollerShutter_01 changed from 27 to 31
2018-11-24 18:28:45.606 [vent.ItemStateChangedEvent] - RS_RollerShutter_01 changed from 31 to 100

chris · November 24, 2018, 5:46pm

Change the repoll period to something longer and it should be fine.

HomeAutomation · November 24, 2018, 5:53pm

Which one:
Polling Period or Command Poll Period?

HomeAutomation · November 24, 2018, 5:54pm

Another error message or just a hint?

2018-11-24 18:36:11.636 [WARN ] [ndclass.ZWaveAlarmSensorCommandClass] - NODE 53: Detected Fibaro FGK - 101 Door / Window sensor, only requesting alarm type Smoke.
2018-11-24 18:38:02.687 [INFO ] [ommandclass.ZWaveVersionCommandClass] - NODE 31: Command Class COMMAND_CLASS_MULTI_CHANNEL has version 0!
2018-11-24 18:47:05.211 [WARN ] [ndclass.ZWaveAlarmSensorCommandClass] - NODE 52: Detected Fibaro FGK - 101 Door / Window sensor, only requesting alarm type Smoke.

HomeAutomation · November 24, 2018, 5:58pm

I changed Command Poll Period to 60000. No effect, same as before

chris · November 24, 2018, 6:26pm

Please provide the logfile.

HomeAutomation · November 24, 2018, 6:36pm

2018-11-24 19:35:05.003 [ome.event.ItemCommandEvent] - Item 'RS_RollerShutter_01' received command UP
2018-11-24 19:35:20.092 [vent.ItemStateChangedEvent] - RS_RollerShutter_01 changed from 0 to 61
2018-11-24 19:35:30.282 [vent.ItemStateChangedEvent] - RS_RollerShutter_01 changed from 61 to 100

Command Poll Period set to 60000

logfile.txt (31.1 KB)

HomeAutomation · November 24, 2018, 6:45pm

It this something I should care? Seams to work.

Device: Fibaro FGK101

2018-11-24 19:38:11.945 [INFO ] [ommandclass.ZWaveVersionCommandClass] - NODE 36: Command Class COMMAND_CLASS_MULTI_CHANNEL has version 0!

HomeAutomation · November 24, 2018, 6:59pm

Some more error logs:

2018-11-24 19:51:09.176 [ERROR] [nal.common.AbstractInvocationHandler] - An error occurred while calling method 'ThingHandler.thingUpdated()' on 'org.openhab.binding.zwave.handler.ZWaveThingHandler@9d41e3': 1
java.lang.ArrayIndexOutOfBoundsException: 1
        at org.openhab.binding.zwave.handler.ZWaveThingHandler.initialiseNode(ZWaveThingHandler.java:226) ~[?:?]
        at org.openhab.binding.zwave.handler.ZWaveThingHandler.bridgeStatusChanged(ZWaveThingHandler.java:512) ~[?:?]
        at org.openhab.binding.zwave.handler.ZWaveThingHandler.initialize(ZWaveThingHandler.java:164) ~[?:?]
        at org.eclipse.smarthome.core.thing.binding.BaseThingHandler.thingUpdated(BaseThingHandler.java:208) ~[?:?]
        at sun.reflect.GeneratedMethodAccessor339.invoke(Unknown Source) ~[?:?]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
        at java.lang.reflect.Method.invoke(Method.java:498) ~[?:?]
        at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:153) [101:org.eclipse.smarthome.core:0.10.0.201811171951]
        at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:53) [101:org.eclipse.smarthome.core:0.10.0.201811171951]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
        at java.lang.Thread.run(Thread.java:748) [?:?]
2018-11-24 19:51:40.926 [INFO ] [ommandclass.ZWaveVersionCommandClass] - NODE 12: Command Class COMMAND_CLASS_MULTI_CHANNEL has version 0!

chris · November 24, 2018, 7:00pm

Since this is a very slow change, the repoll will just need to be disabled since it will only allow you to set it to 15 seconds. Disable this by setting to 0.

Probably not. I’m not sure why it would be 0 - it could be an issue with the device, or some sort of lost response during initialisation. Since most devices just use version 2, which is the default, it should be fine.

HomeAutomation · November 24, 2018, 7:00pm

And another one - should I open a new post for every error to track each in a different post:

2018-11-24 19:53:48.706 [ERROR] [nal.common.AbstractInvocationHandler] - An error occurred while calling method 'ThingHandler.thingUpdated()' on 'org.openhab.binding.zwave.handler.ZWaveThingHandler@1944548': 1
java.lang.ArrayIndexOutOfBoundsException: 1
        at org.openhab.binding.zwave.handler.ZWaveThingHandler.initialiseNode(ZWaveThingHandler.java:226) ~[?:?]
        at org.openhab.binding.zwave.handler.ZWaveThingHandler.bridgeStatusChanged(ZWaveThingHandler.java:512) ~[?:?]
        at org.openhab.binding.zwave.handler.ZWaveThingHandler.initialize(ZWaveThingHandler.java:164) ~[?:?]
        at org.eclipse.smarthome.core.thing.binding.BaseThingHandler.thingUpdated(BaseThingHandler.java:208) ~[?:?]
        at sun.reflect.GeneratedMethodAccessor339.invoke(Unknown Source) ~[?:?]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
        at java.lang.reflect.Method.invoke(Method.java:498) ~[?:?]
        at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:153) [101:org.eclipse.smarthome.core:0.10.0.201811171951]
        at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:53) [101:org.eclipse.smarthome.core:0.10.0.201811171951]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
        at java.lang.Thread.run(Thread.java:748) [?:?]
2018-11-24 19:53:52.738 [WARN ] [ndclass.ZWaveAlarmSensorCommandClass] - NODE 38: Detected Fibaro FGK - 101 Door / Window sensor, only requesting alarm type Smoke.

chris · November 24, 2018, 7:03pm

This is the same as you posted earlier - please provide debug logs. It’s impossible to know what is happening without the logfile - sorry.

Normally these are linked to corrupt frames being received from the device, but without a log, I really can’t say much!

HomeAutomation · November 24, 2018, 7:03pm

perfect, Command Poll Period set to 0 solved this problem.

HomeAutomation · November 24, 2018, 7:04pm

It is very hard to provide a log here. This event comes from time to time. Not sure how to force it. I will do my best

chris · November 24, 2018, 7:05pm

Ok, but there must be data logged just before this error - that’s what I need to see.

HomeAutomation · November 24, 2018, 7:22pm

I will do my best. I have a hint. Looks like it can be solved by changing this parameter to “not sent”. not 100% sure.