[SOLVED] Zwave 2.5 Issues

Have upgraded (fresh install) from 2.4 to 2.5 on qnap NAS
Zwave binding doesn’t want to play ball at all
Says everything online yet nothing works
Using an aeotec stick.
Tried manual config and discovery.
Same result

Any pointers??

It’s really pretty hard to help with so little information. I would recommend reading the binding documentation, and specifically the part toward the end about what to do when things aren’t working.

1 Like

I get little info at this point (on phone so no log access - just got tho).
Didn’t know if anyone else has had problems.
I reinstalled 2.4 and everything works as expected.
Read through all the documentation also.

2020-01-04 14:09:34.563 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Zwave.things'
2020-01-04 14:09:34.822 [INFO ] [zwave.handler.ZWaveControllerHandler] - Attempting to add listener when controller is null
2020-01-04 14:09:34.920 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/ttyACM0'
2020-01-04 14:09:34.970 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Serial port is initialized
2020-01-04 14:09:35.004 [INFO ] [ve.internal.protocol.ZWaveController] - Starting ZWave controller
2020-01-04 14:09:35.005 [INFO ] [ve.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false.
2020-01-04 14:09:35.030 [WARN ] [nal.protocol.ZWaveTransactionManager] - NODE 6: Not initialized (ie node unknown), ignoring message.
2020-01-04 14:09:35.231 [WARN ] [nal.protocol.ZWaveTransactionManager] - NODE 4: Not initialized (ie node unknown), ignoring message.
2020-01-04 14:09:35.308 [WARN ] [nal.protocol.ZWaveTransactionManager] - NODE 7: Not initialized (ie node unknown), ignoring message.
2020-01-04 14:09:35.621 [WARN ] [nal.protocol.ZWaveTransactionManager] - NODE 8: Not initialized (ie node unknown), ignoring message.
2020-01-04 14:09:35.831 [WARN ] [nal.protocol.ZWaveTransactionManager] - NODE 3: Not initialized (ie node unknown), ignoring message.
2020-01-04 14:09:36.027 [WARN ] [nal.protocol.ZWaveTransactionManager] - NODE 6: Not initialized (ie node unknown), ignoring message.
2020-01-04 14:09:36.195 [INFO ] [el.core.internal.ModelRepositoryImpl] - Refreshing model 'Zwave.things'
2020-01-04 14:09:36.231 [WARN ] [nal.protocol.ZWaveTransactionManager] - NODE 4: Not initialized (ie node unknown), ignoring message.
2020-01-04 14:09:36.310 [WARN ] [nal.protocol.ZWaveTransactionManager] - NODE 7: Not initialized (ie node unknown), ignoring message.
2020-01-04 14:09:36.622 [WARN ] [nal.protocol.ZWaveTransactionManager] - NODE 8: Not initialized (ie node unknown), ignoring message.
2020-01-04 14:09:36.827 [WARN ] [nal.protocol.ZWaveTransactionManager] - NODE 3: Not initialized (ie node unknown), ignoring message.
2020-01-04 14:09:37.029 [WARN ] [nal.protocol.ZWaveTransactionManager] - NODE 6: Not initialized (ie node unknown), ignoring message.
2020-01-04 14:09:37.233 [WARN ] [nal.protocol.ZWaveTransactionManager] - NODE 4: Not initialized (ie node unknown), ignoring message.
2020-01-04 14:09:37.313 [WARN ] [nal.protocol.ZWaveTransactionManager] - NODE 7: Not initialized (ie node unknown), ignoring message.
2020-01-04 14:09:37.624 [WARN ] [nal.protocol.ZWaveTransactionManager] - NODE 8: Not initialized (ie node unknown), ignoring message.
2020-01-04 14:09:37.696 [WARN ] [nal.protocol.ZWaveTransactionManager] - NODE 8: Not initialized (ie node unknown), ignoring message.
2020-01-04 14:09:37.823 [WARN ] [nal.protocol.ZWaveTransactionManager] - NODE 3: Not initialized (ie node unknown), ignoring message.
2020-01-04 14:09:38.045 [WARN ] [nal.protocol.ZWaveTransactionManager] - NODE 6: Not initialized (ie node unknown), ignoring message.
2020-01-04 14:09:38.264 [WARN ] [nal.protocol.ZWaveTransactionManager] - NODE 4: Not initialized (ie node unknown), ignoring message.
2020-01-04 14:09:38.319 [WARN ] [nal.protocol.ZWaveTransactionManager] - NODE 7: Not initialized (ie node unknown), ignoring message.
2020-01-04 14:09:40.742 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zwave:device:controller:node6' to inbox.
2020-01-04 14:09:40.745 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zwave:device:controller:node8' to inbox.
2020-01-04 14:09:40.748 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zwave:device:controller:node2' to inbox.
2020-01-04 14:09:40.752 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zwave:device:controller:node7' to inbox.
2020-01-04 14:09:40.756 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zwave:device:controller:node4' to inbox.
2020-01-04 14:09:40.761 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zwave:device:controller:node3' to inbox.
2020-01-04 14:09:40.762 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zwave:device:controller:node5' to inbox.

It might be better to wait till you’re able to access the console and view the logs. Really it would be good to get the debug logs to see what is happening and if you’re unable to access the console you probably can’t get what’s needed.

I do not see where you added these nodes as Things in openHAB. They are discovered but you need to tell OH to add (or ignore) them.

I’ve added them through the things file
I’ve also tried removing thing file, manually adding them through paperui and linking a couple of channels to test, still doesn’t work but still says everything online

That’s the log output i get.
I’m just rebooting my NAS after setting log level to debug, give me 10

The problem is that this is not a debug log - it has INFO level logging, which is fine to show there’s a problem, but DEBUG level is needed to see what is happening.

The messages indicate that youre receiving data from nodes, but the nodes are not initialised yet. Since the binding doesn’t know about them, it ignores the messages. There’s nothing really wrong here, so to understand what is happening, we need more information

It could very well be issues in the Thing definitions too. That is why I always let OH configure Things wherever possible.

2020-01-04 15:06:50.790 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Application Command Request (ALIVE:DONE)

2020-01-04 15:06:50.791 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: resetResendCount initComplete=true isDead=false

2020-01-04 15:06:50.791 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: Decapsulating COMMAND_CLASS_MULTI_CHANNEL

2020-01-04 15:06:50.792 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: Incoming command class COMMAND_CLASS_METER, endpoint 1

2020-01-04 15:06:50.792 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: SECURITY NOT required on COMMAND_CLASS_METER

2020-01-04 15:06:50.793 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 3: Received COMMAND_CLASS_METER V3 METER_REPORT

2020-01-04 15:06:50.793 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 3: Meter: Type=Electric(1), Scale=kWh(0), Value=11.12

2020-01-04 15:06:50.794 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Got an event from Z-Wave network: ZWaveMeterValueEvent

2020-01-04 15:06:50.794 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Got a value event from Z-Wave network, endpoint=1, command class=COMMAND_CLASS_METER, value=11.12

2020-01-04 15:06:50.795 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Updating channel state zwave:fibaro_fgd212_00_000:controller:node3:meter_kwh1 to 11.12 [DecimalType]

2020-01-04 15:06:50.795 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Commands processed 1.

2020-01-04 15:06:50.796 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@5e572454.

2020-01-04 15:06:50.796 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0

2020-01-04 15:06:50.796 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0

2020-01-04 15:06:50.797 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2020-01-04 15:06:50.797 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2020-01-04 15:06:50.938 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 10 00 04 00 06 0A 60 0D 01 01 31 05 04 22 00 FF 67 

2020-01-04 15:06:50.939 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=6, callback=0, payload=00 06 0A 60 0D 01 01 31 05 04 22 00 FF 

2020-01-04 15:06:50.940 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=6, callback=0, payload=00 06 0A 60 0D 01 01 31 05 04 22 00 FF 

2020-01-04 15:06:50.940 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null

2020-01-04 15:06:50.940 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 6: Application Command Request (ALIVE:DONE)

2020-01-04 15:06:50.941 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 6: resetResendCount initComplete=true isDead=false

2020-01-04 15:06:50.941 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 6: Decapsulating COMMAND_CLASS_MULTI_CHANNEL

2020-01-04 15:06:50.942 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 6: Incoming command class COMMAND_CLASS_SENSOR_MULTILEVEL, endpoint 1

2020-01-04 15:06:50.942 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 6: SECURITY NOT required on COMMAND_CLASS_SENSOR_MULTILEVEL

2020-01-04 15:06:50.943 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 6: Received COMMAND_CLASS_SENSOR_MULTILEVEL V4 SENSOR_MULTILEVEL_REPORT

2020-01-04 15:06:50.943 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 6: Sensor Type = Power(4), Scale = 0

2020-01-04 15:06:50.944 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 6: Sensor Value = 25.5

2020-01-04 15:06:50.944 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Got an event from Z-Wave network: ZWaveMultiLevelSensorValueEvent

2020-01-04 15:06:50.945 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Got a value event from Z-Wave network, endpoint=1, command class=COMMAND_CLASS_SENSOR_MULTILEVEL, value=25.5

2020-01-04 15:06:50.946 [DEBUG] [erter.ZWaveMultiLevelSensorConverter] - NODE 6: Sensor conversion not performed for POWER.

2020-01-04 15:06:50.946 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Updating channel state zwave:fibaro_fgd212_00_000:controller:node6:sensor_power1 to 25.5 [DecimalType]

2020-01-04 15:06:50.947 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 6: Commands processed 1.

2020-01-04 15:06:50.948 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 6: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@32d45469.

2020-01-04 15:06:50.948 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0

2020-01-04 15:06:50.948 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0

2020-01-04 15:06:50.949 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2020-01-04 15:06:50.949 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2020-01-04 15:06:51.163 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 10 00 04 00 03 0A 60 0D 01 01 31 05 04 22 00 0A 97 

2020-01-04 15:06:51.165 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=3, callback=0, payload=00 03 0A 60 0D 01 01 31 05 04 22 00 0A 

2020-01-04 15:06:51.165 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=3, callback=0, payload=00 03 0A 60 0D 01 01 31 05 04 22 00 0A 

2020-01-04 15:06:51.166 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null

It could be… At the moment I see no problem from the information provided. The logs look fine, so more information is required to understand what is actually wrong (if anything).

The above are the only logs I get, same for every node
Looking it seems everything is ok but it’s not

Please use code fences - I’ve edited this for you. Better still, post full logs as files (there are many places to host such files and you can just provide the link here). This gets around having to post small files to get around limits and makes things a lot easier to debug for you.

Please provide the full logs. This is simply a report being received - it shows everything is working fine with this device.

Please also explain your problem - currently you just say -:

this is really not enough to understand what doesn’t work?

Hi Chris,

i have the same problem. Update from 2.4 to 2.5.
my “MT02650 Devolo Thermostat” works.
In Webinterface the “NAS-DS01Z Door/Window Sensor” looks good und work befor update.

with Debug an open/close Window - No information at the log.

Here is a Log if i search for neu MQTT Things.
My NAS-DS01Z have Node 9, 11, 12 and 13.
i hope this will help

zwave.log (296.3 KB)

Done a little more testing, seems some nodes function, others do not. Now I’ve worked out some of them are working I’m going to do some more testing. Somethings not right though

Just see this pop up when removing and reading binding:

2020-01-05 08:09:09.244 [ERROR] [nal.common.AbstractInvocationHandler] - An error occurred while calling method 'ThingHandler.initialize()' on 'org.openhab.binding.zwave.handler.ZWaveSerialHandler@2f816c2a': bundleContext
java.lang.NoSuchFieldError: bundleContext
at org.openhab.binding.zwave.handler.ZWaveControllerHandler.initializeNetwork(ZWaveControllerHandler.java:197) ~[?:?]
at org.openhab.binding.zwave.handler.ZWaveSerialHandler.initialize(ZWaveSerialHandler.java:98) ~[?:?]
at sun.reflect.GeneratedMethodAccessor79.invoke(Unknown Source) ~[?:?]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_201]
at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_201]
at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:152) [bundleFile:?]
at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:52) [bundleFile:?]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_201]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_201]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_201]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_201]
2020-01-05 08:09:09.250 [ERROR] [core.thing.internal.ThingManagerImpl] - Exception occurred while initializing handler of thing 'zwave:serial_zstick:controller': bundleContext
java.lang.NoSuchFieldError: bundleContext
at org.openhab.binding.zwave.handler.ZWaveControllerHandler.initializeNetwork(ZWaveControllerHandler.java:197) ~[?:?]
at org.openhab.binding.zwave.handler.ZWaveSerialHandler.initialize(ZWaveSerialHandler.java:98) ~[?:?]
at sun.reflect.GeneratedMethodAccessor79.invoke(Unknown Source) ~[?:?]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_201]
at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_201]
at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:152) [bundleFile:?]
at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:52) [bundleFile:?]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_201]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_201]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_201]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_201]

These sort of exceptions (NoSuchField and ClassNotFound) are indicative of a mismatch in versions. It normally means that the compiler thought that these fields existed, or it would not have compiled, but they don’t exist at runtime - meaning the compilation environment is different to the runtime environment.

I’m really not sure what to say here. As it is very unclear from the OP what the issue is, and it’s also totally unclear what issue your’e reporting, I’m not sure how they are “the same problem” :roll_eyes: .

That aside, without more information it’s really impossible for me to help - sorry.

at Paper UI all looks ok.
my window contact is online ans its recognized as “NAS-DS01Z Door/Window Sensor”.
But if i open or close a window, nothing.
it worked one year in openhab2.4.