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

Nope - I’ve not updated the binding since last weekend I think, so for sure nothing has changed recently. Before that I changed the matching of the database type/id, but that’s unlikely to affect this.

@chris

It’s pretty strange then. My battery powered lock showed up just fine. Yet both door sensors show communication problems. I will grab my monoprice garage door sensor again; open it up and manually wake it again. That one shows as a ZG8101

My Aeotec recessed door sensor continue show as unknown, but think that could be a database or other issue.

The garage door one has always worked well.

Other than the database update, and the fix to the switch_all configuration, there’s been no changes to the binding since the 5th Feb, so I can’t see what should have caused that. It might just be a latent bug - I would suggest to look at the logs.

Still have some problems adding my Danalock…
Excluded the lock from the network and added it again still no luck.
I still have these Errors with this version of zwave: 190 | Active | 80 | 2.1.0.201702122241 | ZWave Binding
Any clue?

2017-02-17 19:32:25.123 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:15a32b9cacd:node19.
2017-02-17 19:32:25.124 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:15a32b9cacd:node16.
2017-02-17 19:32:25.125 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:15a32b9cacd:node12.
2017-02-17 19:32:25.126 [ERROR] [ome.core.thing.link.ThingLinkManager] - Exception occured while informing handler:null
java.lang.UnsupportedOperationException
        at java.util.AbstractList.add(AbstractList.java:148)[:1.8.0_121]
        at java.util.AbstractList.add(AbstractList.java:108)[:1.8.0_121]
        at org.openhab.binding.zwave.handler.ZWaveThingHandler.channelLinked(ZWaveThingHandler.java:432)[190:org.openhab.binding.zwave:2.1.0.201702122241]
        at org.eclipse.smarthome.core.thing.link.ThingLinkManager.informHandlerAboutLinkedChannel(ThingLinkManager.java:264)[105:org.eclipse.smarthome.core.thing:0.9.0.201702100936]
        at org.eclipse.smarthome.core.thing.link.ThingLinkManager.receiveTypedEvent(ThingLinkManager.java:304)[105:org.eclipse.smarthome.core.thing:0.9.0.201702100936]
        at org.eclipse.smarthome.core.thing.link.ThingLinkManager.receiveTypedEvent(ThingLinkManager.java:1)[105:org.eclipse.smarthome.core.thing:0.9.0.201702100936]
        at org.eclipse.smarthome.core.events.AbstractTypedEventSubscriber.receive(AbstractTypedEventSubscriber.java:50)[98:org.eclipse.smarthome.core:0.9.0.201702100936]
        at org.eclipse.smarthome.core.internal.events.OSGiEventManager$1.call(OSGiEventManager.java:192)[98:org.eclipse.smarthome.core:0.9.0.201702100936]
        at org.eclipse.smarthome.core.internal.events.OSGiEventManager$1.call(OSGiEventManager.java:1)[98:org.eclipse.smarthome.core:0.9.0.201702100936]
        at org.eclipse.smarthome.core.common.SafeMethodCaller$CallableWrapper.call(SafeMethodCaller.java:181)[98:org.eclipse.smarthome.core:0.9.0.201702100936]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)[:1.8.0_121]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)[:1.8.0_121]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)[:1.8.0_121]
        at java.lang.Thread.run(Thread.java:745)[:1.8.0_121]
2017-02-17 19:32:25.127 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:15a32b9cacd:node13.

I got both sensors to wake up and report after ‘waking’ them about 5 or 6 time each. I was able to monitor it open-zwave to see when the finally woke up.

But I do know the Aeotec recessed door sensor I have still continues to show as unknown device.

@TordYevl

Tommy, I believe that error your seeing in the log may be do the trying to find devices before the controller is started, or something to that affect. Can you confirm that error stops in your log after your controller comes online?

Also, as reported earlier by shawnmix, I am also seeing the Send Data was not placed on stack error 2 nodes.

2017-02-17 14:08:15.466 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 2: Sent Data was not placed on stack.
2017-02-17 14:08:15.480 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 10: Sent Data was not placed on stack.
2017-02-17 14:08:15.487 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 2: Sent Data was not placed on stack.
2017-02-17 14:08:15.510 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 2: Sent Data was not placed on stack.
2017-02-17 14:08:15.527 [ERROR] [lmessage.RequestNodeInfoMessageClass] - Request node info not placed on stack due to error.
2017-02-17 14:08:15.543 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 2: Sent Data was not placed on stack.
2017-02-17 14:08:15.566 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 2: Sent Data was not placed on stack.
2017-02-17 14:08:21.881 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 2: Sent Data was not placed on stack.
2017-02-17 14:08:21.889 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 10: Sent Data was not placed on stack.

Node 2 is my lock and Node 10 is powered switch. I am using an Aeotec Gen5 Controller.

@ptmuldoon The major part is intially before the controller starts but I also see it when I delete my lock and add it back in again.
Not always but often.
To clarify my lock is found and recognized correctly but without “using security”, which means I’m unabke to control it.

This looks like the polling issue - I thought I’d fixed this but maybe not. I’ll try and update to resolve this one as it should be easy.

You really need to provide debug logs. This error simply means that the stick was not able to process the message. Why is probably difficult to tell even with debug logs, but for sure, without them it’s absolutely impossible.

Do you have a log that shows the secure inclusion not working?

Can you confirm you removed the device from your controller and then re-included? Not just deleted the device from within Habmin and Re-Added. But you need to actually unpair from your controller and then re-include. You only need to do that once and then save your Security Key someplace so you can readd to Habmin in the future if you need to.

Yepp, excluded the node, changed the networks security key to a known value and re-added the node.
It got a new node number
I tried to turn on zwave debug to see if I can find anything to indicate why it doesn’t work.
I couldn’t find anything concrete but the actual errors that I posted before.
Will however continue to investigate :slight_smile:

If you send me the log I’ll take a look if you like?

@TordYevl

I was reading up on at that lock and see it includes both BT and Zwave in it. But I couldn’t find any information on it regarding if it was Zwave Plus or not. Just throwing ideas out there that maybe your controller is Zwave and the device is Zwave Plus and causing an issue.

Also, what OS are you running OH2 on? What I did to troubleshoot things in the past was to install open-zwave-control-plael on my Ubuntu machine. And you can then set your same network key in ozcp and try in there. That can help trouble shoot if its the binding or something else. You just can run OH2 and ozcp at the same time. So just stop OH2, startup ozcp and you can connect to your controller and check if your lock works there.

If you need help setting up ozcp, let me know. I remember you need to make it from the source, but there are a couple of good how-to’s on the web.

That shouldn’t ever be an issue. ZWave plus has two parts - half is how the binding is written (ie there’s new command classes), and the other half is how the hardware is designed (eg higher data rates, and higher RF power). Generally, things are backward compatible so this shouldn’t be an issue.

I would really prefer that you didn’t - I’d much prefer that instead of finding a workaround, we instead find the problem - otherwise it’s not helping others, and I end up wasting a lot of time trying to find the same problem each time :frowning: . I appreciate that it can be frustrating when things don’t work (for me as well!), and it might be easier to just work around things, but if we can actually find the problem I would really appreciate the help.

I’ve been looking through the logs anyway and have updated the binding - let’s see how things go before reverting to other software!

I only mentioned from a testing perspective. To see if his locked worked there or not. It could simply be the lock and nothing with OH2 or the binding. I read the reviews of the V1 Dalelock and seems lot of people have issues with it, but the V2 seemed better.

Only trying to provide some troubleshooting options :slight_smile:

It appears to work with OH2 already, but there are many exceptions that need to be fixed (which I hope I’ve done, but waiting for feedback)…

Thanks for helping me out here…
I’m using Ubuntu 16.4 and I have had the lock working with the first version of this binding, so I know the lock is working.

I did try the new binding and I didn’t se the same exception, deleting the lock in habmin gave me a different error.
But after a while the whole zwave parts stopped and doesn’t come back after restart.
All question marks in habmin.

16:52:13.887 [INFO ] [marthome.event.ItemStateChangedEvent] - node9_sensor_temperature changed from 22.8 to 22.9
16:52:37.567 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:15a32b9cacd:node19' changed from ONLINE to UNINITIALIZED
16:52:37.578 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:15a32b9cacd:node19' changed from ONLINE to UNINITIALIZED (HANDLER_MISSING_ERROR)
16:52:37.579 [INFO ] [smarthome.event.ThingRemovedEvent   ] - Thing 'zwave:device:15a32b9cacd:node19' has been removed.
16:52:41.939 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zwave:device:15a32b9cacd:node19' to inbox.
16:52:41.940 [INFO ] [smarthome.event.InboxAddedEvent     ] - Discovery Result with UID 'zwave:device:15a32b9cacd:node19' has been added.
16:52:46.966 [INFO ] [smarthome.event.InboxRemovedEvent   ] - Discovery Result with UID 'zwave:device:15a32b9cacd:node19' has been removed.
16:52:46.967 [INFO ] [smarthome.event.ThingAddedEvent     ] - Thing 'zwave:device:15a32b9cacd:node19' has been added.
16:52:46.971 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:15a32b9cacd:node19' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline
16:52:46.971 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:15a32b9cacd:node19' changed from UNINITIALIZED to INITIALIZING
16:52:46.975 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:15a32b9cacd:node19' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to UNINITIALIZED
16:52:46.976 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:15a32b9cacd:node19' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
16:52:46.993 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:15a32b9cacd:node19' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline
16:52:46.993 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:15a32b9cacd:node19' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING
16:52:46.994 [INFO ] [smarthome.event.ThingUpdatedEvent   ] - Thing 'zwave:device:15a32b9cacd:node19' has been updated.
16:52:46.995 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:15a32b9cacd:node19' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
16:52:50.236 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:15a32b9cacd:node10' changed from OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller to ONLINE
16:53:29.798 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:15a32b9cacd:node8' changed from OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller to ONLINE
16:53:29.891 [INFO ] [marthome.event.ItemStateChangedEvent] - node8_sensor_luminance changed from 917.0 to 8
16:53:30.072 [INFO ] [marthome.event.ItemStateChangedEvent] - node8_sensor_temperature changed from 23.5 to 23.7
16:54:29.270 [INFO ] [marthome.event.ConfigStatusInfoEvent] - ConfigStatusInfo [configStatusMessages=[]]
16:54:29.270 [INFO ] [smarthome.event.ThingUpdatedEvent   ] - Thing 'zwave:device:15a32b9cacd:node4' has been updated.
16:54:29.271 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 9: Sent Data was not placed on stack.
16:54:29.271 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:15a32b9cacd:node4' changed from ONLINE: Node initialising: REQUEST_NIF to ONLINE
16:54:29.277 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 6: Sent Data was not placed on stack.
16:54:29.282 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 4: Sent Data was not placed on stack.
16:54:29.285 [ERROR] [lmessage.RequestNodeInfoMessageClass] - Request node info not placed on stack due to error.
16:54:29.290 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:15a32b9cacd:node7' changed from OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller to ONLINE
16:54:29.291 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:15a32b9cacd:node7' changed from ONLINE to ONLINE: Node initialising: REQUEST_NIF
16:54:29.359 [ERROR] [ome.core.thing.internal.ThingManager] - Exception occured while calling thing updated at ThingHandler 'org.openhab.binding.zwave.handler.ZWaveThingHandler@182ddd80': java.lang.ClassCastException: java.lang.String cannot be cast to java.math.BigDecimal
java.util.concurrent.ExecutionException: java.lang.ClassCastException: java.lang.String cannot be cast to java.math.BigDecimal
	at java.util.concurrent.FutureTask.report(FutureTask.java:122)[:1.8.0_121]
	at java.util.concurrent.FutureTask.get(FutureTask.java:206)[:1.8.0_121]
	at org.eclipse.smarthome.core.common.SafeMethodCaller.callAsynchronous(SafeMethodCaller.java:194)[98:org.eclipse.smarthome.core:0.9.0.201702100936]
	at org.eclipse.smarthome.core.common.SafeMethodCaller.call(SafeMethodCaller.java:83)[98:org.eclipse.smarthome.core:0.9.0.201702100936]
	at org.eclipse.smarthome.core.common.SafeMethodCaller.call(SafeMethodCaller.java:67)[98:org.eclipse.smarthome.core:0.9.0.201702100936]
	at org.eclipse.smarthome.core.thing.internal.ThingManager.thingUpdated(ThingManager.java:506)[105:org.eclipse.smarthome.core.thing:0.9.0.201702100936]
	at org.eclipse.smarthome.core.thing.internal.ThingRegistryImpl.notifyTrackers(ThingRegistryImpl.java:227)[105:org.eclipse.smarthome.core.thing:0.9.0.201702100936]
	at org.eclipse.smarthome.core.thing.internal.ThingRegistryImpl.notifyListenersAboutUpdatedElement(ThingRegistryImpl.java:150)[105:org.eclipse.smarthome.core.thing:0.9.0.201702100936]
	at org.eclipse.smarthome.core.thing.internal.ThingRegistryImpl.notifyListenersAboutUpdatedElement(ThingRegistryImpl.java:1)[105:org.eclipse.smarthome.core.thing:0.9.0.201702100936]
	at org.eclipse.smarthome.core.common.registry.AbstractRegistry.updated(AbstractRegistry.java:167)[98:org.eclipse.smarthome.core:0.9.0.201702100936]
	at org.eclipse.smarthome.core.common.registry.AbstractProvider.notifyListeners(AbstractProvider.java:57)[98:org.eclipse.smarthome.core:0.9.0.201702100936]
	at org.eclipse.smarthome.core.common.registry.AbstractProvider.notifyListenersAboutUpdatedElement(AbstractProvider.java:82)[98:org.eclipse.smarthome.core:0.9.0.201702100936]
	at org.eclipse.smarthome.core.common.registry.AbstractManagedProvider.update(AbstractManagedProvider.java:134)[98:org.eclipse.smarthome.core:0.9.0.201702100936]
	at org.eclipse.smarthome.config.discovery.internal.PersistentInbox.add(PersistentInbox.java:204)[95:org.eclipse.smarthome.config.discovery:0.9.0.201702100936]
	at org.eclipse.smarthome.config.discovery.internal.PersistentInbox.thingDiscovered(PersistentInbox.java:293)[95:org.eclipse.smarthome.config.discovery:0.9.0.201702100936]
	at org.eclipse.smarthome.config.discovery.internal.DiscoveryServiceRegistryImpl$2.run(DiscoveryServiceRegistryImpl.java:269)[95:org.eclipse.smarthome.config.discovery:0.9.0.201702100936]
	at org.eclipse.smarthome.config.discovery.internal.DiscoveryServiceRegistryImpl$2.run(DiscoveryServiceRegistryImpl.java:1)[95:org.eclipse.smarthome.config.discovery:0.9.0.201702100936]
	at java.security.AccessController.doPrivileged(Native Method)[:1.8.0_121]
	at org.eclipse.smarthome.config.discovery.internal.DiscoveryServiceRegistryImpl.thingDiscovered(DiscoveryServiceRegistryImpl.java:266)[95:org.eclipse.smarthome.config.discovery:0.9.0.201702100936]
	at org.eclipse.smarthome.config.discovery.AbstractDiscoveryService.thingDiscovered(AbstractDiscoveryService.java:253)[95:org.eclipse.smarthome.config.discovery:0.9.0.201702100936]
	at org.openhab.binding.zwave.discovery.ZWaveDiscoveryService.deviceDiscovered(ZWaveDiscoveryService.java:130)[190:org.openhab.binding.zwave:2.1.0.201702181307]
	at org.openhab.binding.zwave.handler.ZWaveControllerHandler.ZWaveIncomingEvent(ZWaveControllerHandler.java:560)[190:org.openhab.binding.zwave:2.1.0.201702181307]
	at org.openhab.binding.zwave.internal.protocol.ZWaveController.notifyEventListeners(ZWaveController.java:549)[190:org.openhab.binding.zwave:2.1.0.201702181307]
	at org.openhab.binding.zwave.internal.protocol.serialmessage.AddNodeMessageClass.handleRequest(AddNodeMessageClass.java:147)[190:org.openhab.binding.zwave:2.1.0.201702181307]
	at org.openhab.binding.zwave.internal.protocol.ZWaveController.handleIncomingRequestMessage(ZWaveController.java:228)[190:org.openhab.binding.zwave:2.1.0.201702181307]
	at org.openhab.binding.zwave.internal.protocol.ZWaveController.handleIncomingMessage(ZWaveController.java:196)[190:org.openhab.binding.zwave:2.1.0.201702181307]
	at org.openhab.binding.zwave.internal.protocol.ZWaveTransactionManager$ZWaveReceiveThread.run(ZWaveTransactionManager.java:533)[190:org.openhab.binding.zwave:2.1.0.201702181307]
Caused by: java.lang.ClassCastException: java.lang.String cannot be cast to java.math.BigDecimal
	at org.openhab.binding.zwave.handler.ZWaveThingHandler.initialize(ZWaveThingHandler.java:123)[190:org.openhab.binding.zwave:2.1.0.201702181307]
	at org.eclipse.smarthome.core.thing.binding.BaseThingHandler.thingUpdated(BaseThingHandler.java:192)[105:org.eclipse.smarthome.core.thing:0.9.0.201702100936]
	at org.eclipse.smarthome.core.thing.internal.ThingManager$7.call(ThingManager.java:510)[105:org.eclipse.smarthome.core.thing:0.9.0.201702100936]
	at org.eclipse.smarthome.core.thing.internal.ThingManager$7.call(ThingManager.java:1)[105:org.eclipse.smarthome.core.thing:0.9.0.201702100936]
	at org.eclipse.smarthome.core.common.SafeMethodCaller$CallableWrapper.call(SafeMethodCaller.java:181)[98:org.eclipse.smarthome.core:0.9.0.201702100936]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)[:1.8.0_121]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)[:1.8.0_121]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)[:1.8.0_121]
	at java.lang.Thread.run(Thread.java:745)[:1.8.0_121]
16:54:29.363 [INFO ] [smarthome.event.ThingUpdatedEvent   ] - Thing 'zwave:device:15a32b9cacd:node19' has been updated.
16:54:29.363 [INFO ] [smarthome.event.BindingEvent        ] - org.openhab.binding.zwave.event.BindingEvent@c7e2cc5
16:54:29.368 [INFO ] [smarthome.event.BindingEvent        ] - org.openhab.binding.zwave.event.BindingEvent@837a4

17:05:28.578 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:15a32b9cacd:node16' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
17:05:28.579 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:15a32b9cacd:node19' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
17:05:28.580 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:15a32b9cacd:node12' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
17:05:28.581 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:15a32b9cacd:node13' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
17:05:28.581 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:15a32b9cacd:node14' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
17:05:28.582 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:15a32b9cacd:node15' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
17:05:28.583 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:15a32b9cacd:node7' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
17:05:28.583 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:15a32b9cacd:node8' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
17:05:28.584 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:15a32b9cacd:node9' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
17:05:28.585 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:15a32b9cacd:node10' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
17:05:28.586 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:15a32b9cacd:node11' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
17:05:28.587 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:15a32b9cacd:node2' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
17:05:28.588 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:15a32b9cacd:node3' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
17:05:28.589 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:15a32b9cacd:node4' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
17:05:28.589 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:15a32b9cacd:node5' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
17:05:28.590 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:15a32b9cacd:node6' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
your code goes here

From the log, it looks like it’s securely including as well -:

The first line shows that it is securely included, but then it seems later you’re trying to include it again - this won’t work with secure devices… There’s not a lot of debug data unfortunately so not much to say.

I’m not really sure why this would show up. It’s caused by some configuration not being the right type - seemingly the nodeid is not an integer. It’s hard to tell from the log what node this is for - debug logging would be better as there’s a message that gets printed just before this message.

Did a complete re-installation but still see the cast error from String to BigDecimal.
To see if the lock is included with security I use habmin in the thing menu and attribute Using Security.
Could that give misleading information?

I have been follow this for the last week now and would like to report that I have everything back up and running and have successfully paired my BE469 (Schlage). I can unlock and lock via Zwave. The only issue I am seeing is that the lock does not update status if I unlock and lock from the lock itself. I am also seeing this in my logs:

[l.serialmessage.SendDataMessageClass] - NODE 46: Sent Data was not placed on stack.

Node 46 is the BE469. Chris, I cant thank you enough for your hard work on this. I started my home automation project with a security system in mind and could not have finished it without the updates you have made.

So @chris, from the result of your analysis I should be searching for “SECURITY_INC State=” in my logs…
I only seem to find it if I totally remove my lock from my controller and add it again, and then unfortunately with “SECURITY_INC State=FAILED”.
Is there a way to re-negotiate security without removing it from the controller? (it steps node number every time)
Only deleting it in HABmin doesn’t seem to do that.
I filled in my own network security key, is there any rules for the syntax?
I used characters A-F and 0-9 in octets with space in between, 16 of them.