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

Hmmm - ok, I’ve not seen HABmin display that before so I don’t know what that means. If it happens again, please can you grab a screenshot.

I have nodes that does not mesh properly (2.1.0 SNAPSHOT #858)


(HABmin graph reflects neighbours in things property)

All nodes, except #12 are fairly close to the controller, but for some reason node #35 is very popular.

I understand by using this developer version of the binding, this mesh issue is fixed?

@chris : I then wonder, if I just wait, will it be merged to the SNAPSHOT branch eventually and will that binding update be automatic, or will we at that time need to delete and add all nodes once more?

If I manually replace my SNAPSHOT binding with this one, what will happen if I do a SNAPSHOT upgrade at a later time?

My network works fine as it is, but mesh wise it seems a bit odd?

Yes - the plan is to merge it after the 2.1 release is made. Unfortunately as there are a lot of changes it will require you to delete all things and add them back - that doesn’t mean exclude and include - just deleting the things so that the new definitions are added.

You can’t really swap between the two as the thing definitions are different.

Thanks @chris for clearing that up.

Regarding my node neighbours and meshing, will switching to the new binding make any real difference, or it is just the graph that will look prettier?

Is there, in that case, any other tools that will list the controllers perception of neighbouring nodes?
(or is it that I am seeing already? :slight_smile: )

So following up this strange ZW089 recessed door issue.

It appears to be showing correctly in habmin, but the battery level is not being reported/shown.

And what is strange is that PaperUI will not let me enable/disable a channel, and I get a 404 error when trying.

EDIT… And now it’s working. I really think this door sensor is defective!!

For me Zwave is working much better after switching to the development binding.
I got a much stabler network and the nodes are seeing each other instead of only the controller.

br,
Raymond

Potentially yes, it can make a difference. The new code updates the neighbour list every evening which might help with routing.

Yes - this is what you are seeing already.

I have an issue with the new binding with my Fibaro FGMS001 motions sensors. Every time an alarm is triggered (eg motion, tamper) there is no update in OH2. In the Karaf console I can see that every time a java exception is thrown:

 java.lang.reflect.InvocationTargetException
        at sun.reflect.GeneratedMethodAccessor84.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
        at java.lang.reflect.Method.invoke(Unknown Source)
        at org.openhab.binding.zwave.internal.protocol.commandclass.ZWaveCommand
Class.handleApplicationCommandRequest(ZWaveCommandClass.java:245)
        at org.openhab.binding.zwave.internal.protocol.ZWaveNode.processCommand(
ZWaveNode.java:1284)
        at org.openhab.binding.zwave.internal.protocol.ZWaveTransactionManager$Z
WaveReceiveThread.run(ZWaveTransactionManager.java:413)
Caused by: java.lang.NullPointerException
        at org.openhab.binding.zwave.internal.protocol.commandclass.ZWaveAlarmCo
mmandClass.handleNotificationReport(ZWaveAlarmCommandClass.java:140)

Then other channels (temperature, luminance etc.) are reported correctly.

I am using OH210 snapshot 889 with experimental Z Wave binding 2.1.0.201704171736

I cannot provide a debug log beacuse nothing from that event appears in the logs. The Karaf console java exception is the only trace of the problem.

Please can you provide the debug log that shows the receive message just before the exception is thrown.

Thanks.

Ok, this should be the relevant lines (node 116):

2017-04-23 11:30:27.408 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0F 00 04 00 74 09 71 05 00 00 00 FF 07 08 00 0D 
2017-04-23 11:30:27.409 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT 6
2017-04-23 11:30:27.409 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage inputMessage: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=116, callback=0, payload=00 74 09 71 05 00 00 00 FF 07 08 00 
2017-04-23 11:30:27.409 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lockMessage: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=116, callback=0, payload=00 74 09 71 05 00 00 00 FF 07 08 00 
2017-04-23 11:30:27.409 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=116, callback=0, payload=00 74 09 71 05 00 00 00 FF 07 08 00 
2017-04-23 11:30:27.409 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2017-04-23 11:30:27.409 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 116: Application Command Request (ALIVE:DONE)
2017-04-23 11:30:27.409 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 116: resetResendCount initComplete=true isDead=false
2017-04-23 11:30:27.409 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 116: Incoming command class COMMAND_CLASS_ALARM, endpoint 0
2017-04-23 11:30:27.409 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 116: SECURITY NOT required on COMMAND_CLASS_ALARM
2017-04-23 11:30:27.409 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 116: Received COMMAND_CLASS_ALARM V5 NOTIFICATION_REPORT
2017-04-23 11:30:27.410 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 116: Commands processed 1.
2017-04-23 11:30:27.410 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 116: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@7f847486.
2017-04-23 11:30:27.410 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2017-04-23 11:30:27.410 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2017-04-23 11:30:27.410 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2017-04-23 11:30:27.410 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start
2017-04-23 11:30:27.410 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 117: listening == false, frequentlyListening == false, awake == false
2017-04-23 11:30:27.410 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 117: Node not awake!

Thanks. Unfortunately I can’t find any problem. I’ve written a test to process the received packet from your log and it works fine.

I’ll do an update of the binding later today - let’s see if it still exists and if so please send the same information again (ie exception log, and the event leading up to it).

Cheers
Chris

Thank you very much for the quick analysis. Then I will try the new binding when you updated it.

I’ve put an updated binding on the download site. This addresses a few things, but the main change is an update to user_code to support keypads that require hex values. In this case, hex codes can be written like “11 22 AA BB”. Note that this is to support locks that are not adhering to the ZWave standard, so this might change in future.

The database has also been updated to includes updates up to this morning.

Running into an issue with latest where logs stop for several minutes.

017-04-23 15:21:31.978 [ZWaveNodeInitStageAdvancer] - NODE 67: Node Init response (1) TIMEOUT_WAITING_FOR_CONTROLLER
2017-04-23 15:21:31.978 [SerialMessage             ] - Calculated checksum = 0x19
2017-04-23 15:21:31.978 [SerialMessage             ] - Assembled message buffer = 01 0A 00 13 60 03 86 13 25 25 09 19 
2017-04-23 15:21:31.978 [ZWaveSerialHandler        ] - NODE 96: Sending REQUEST Message = 01 0A 00 13 60 03 86 13 25 25 09 19 
2017-04-23 15:21:33.790 [ZWaveTransactionManager   ] - NODE 13: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@37fcd2ed
2017-04-23 15:21:37.875 [ZWaveTransactionManager   ] - NODE 67: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@77f7769c
2017-04-23 15:24:28.928 [ZWaveSerialHandler        ] - Message SENT
2017-04-23 15:24:28.928 [ZWaveTransaction          ] - TID 89: Transaction Start type SendData 
2017-04-23 15:24:28.928 [ZWaveTransactionManager   ] - Transaction SendNextMessage started: TID 89: [WAIT_RESPONSE] requiresResponse=true callback: 9
2017-04-23 15:24:28.928 [ZWaveTransactionManager   ] - Transaction SendNextMessage started: expected cmd class: COMMAND_CLASS_VERSION
2017-04-23 15:24:28.928 [ZWaveTransactionManager   ] - Transaction SendNextMessage started: expected cmd: 20
2017-04-23 15:24:28.928 [ZWaveTransactionManager   ] - Transaction SendNextMessage Transactions outstanding: 1

And:

2017-04-23 15:25:05.526 [ZWaveTransactionManager   ] - NODE 255: -- To notify -- TIMEOUT_WAITING_FOR_CONTROLLER
2017-04-23 15:25:05.526 [SerialMessage             ] - NODE 96: Creating empty message of class = SendData (0x13), type = Request (0x00)
2017-04-23 15:25:05.526 [SerialMessage             ] - Calculated checksum = 0xD8
2017-04-23 15:25:05.526 [ZWaveTransactionManager   ] - ********* Transaction Response Complete 101 -- 
2017-04-23 15:25:05.526 [SerialMessage             ] - Assembled message buffer = 01 0A 00 13 60 03 70 05 01 25 0C D8 
2017-04-23 15:25:05.526 [ZWaveNodeInitStageAdvancer] - NODE 55: Node Init response (0) TIMEOUT_WAITING_FOR_CONTROLLER
2017-04-23 15:25:05.526 [ZWaveSerialHandler        ] - NODE 96: Sending REQUEST Message = 01 0A 00 13 60 03 70 05 01 25 0C D8 
2017-04-23 15:25:06.699 [ZWaveTransactionManager   ] - NODE 255: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@3b47e18b
2017-04-23 15:25:13.596 [ZWaveTransactionManager   ] - NODE 67: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@77f7769c
2017-04-23 15:37:06.234 [ZWaveSerialHandler        ] - Message SENT
2017-04-23 15:37:06.234 [ZWaveTransaction          ] - TID 154: Transaction Start type SendData 
2017-04-23 15:37:06.234 [ZWaveTransactionManager   ] - Transaction SendNextMessage started: TID 154: [WAIT_RESPONSE] requiresResponse=true callback: 12
2017-04-23 15:37:06.234 [ZWaveTransactionManager   ] - Transaction SendNextMessage started: expected cmd class: COMMAND_CLASS_CONFIGURATION
2017-04-23 15:37:06.234 [ZWaveTransactionManager   ] - Transaction SendNextMessage started: expected cmd: 6
2017-04-23 15:37:06.234 [ZWaveTransactionManager   ] - Transaction SendNextMessage Transactions outstanding: 1

And:

2017-04-23 15:38:16.269 [ZWaveTransactionManager   ] - Start transaction timer to Sun Apr 23 15:38:17 EDT 2017 - 1255ms
2017-04-23 15:38:17.524 [ager$ZWaveTransactionTimer] - XXXXXXXXX Timeout.......... 1 outstanding transactions
2017-04-23 15:38:17.524 [ager$ZWaveTransactionTimer] - NODE 4: TID 241: Timeout at state WAIT_RESPONSE. 3 retries remaining.
2017-04-23 15:38:17.524 [ager$ZWaveTransactionTimer] - TID 241: Transaction is current transaction, so clearing!!!!!
2017-04-23 15:38:17.524 [ZWaveTransaction          ] - TID 241: Transaction CANCELLED
2017-04-23 15:38:17.524 [ZWaveController           ] - Notifying event listeners: ZWaveTransactionCompletedEvent
2017-04-23 15:38:17.524 [ZWaveThingHandler         ] - NODE 4: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2017-04-23 15:38:17.524 [ZWaveTransactionManager   ] - NODE 4: notifyTransactionResponse TID:241 CANCELLED
2017-04-23 15:38:17.524 [ZWaveTransactionManager   ] - Transaction SendNextMessage 0 out at start
2017-04-23 15:38:17.525 [ZWaveTransactionManager   ] - TID 241: Transaction event listener: DONE: CANCELLED -> 
2017-04-23 15:38:17.525 [ZWaveNode                 ] - NODE 78: listening == false, frequentlyListening == false, awake == false
2017-04-23 15:38:17.525 [ZWaveTransactionManager   ] - NODE 78: Node not awake!
2017-04-23 15:38:17.525 [ZWaveTransactionManager   ] - NODE 4: -- To notify -- TIMEOUT_WAITING_FOR_CONTROLLER
2017-04-23 15:38:17.525 [ZWaveNode                 ] - NODE 6: listening == true, frequentlyListening == false, awake == false
2017-04-23 15:38:17.525 [ZWaveTransactionManager   ] - Transaction from sendQueue
2017-04-23 15:38:17.525 [ZWaveTransactionManager   ] - ********* Transaction Response Complete 241 -- 
2017-04-23 15:38:17.525 [ZWaveTransactionManager   ] - getTransactionToSend 6
2017-04-23 15:38:17.525 [ZWaveNodeInitStageAdvancer] - NODE 4: Node Init response (1) TIMEOUT_WAITING_FOR_CONTROLLER
2017-04-23 15:38:17.525 [SerialMessage             ] - NODE 255: Creating empty message of class = RequestNodeInfo (0x60), type = Request (0x00)
2017-04-23 15:38:17.525 [SerialMessage             ] - Calculated checksum = 0x9D
2017-04-23 15:38:17.525 [SerialMessage             ] - Assembled message buffer = 01 04 00 60 06 9D 
2017-04-23 15:38:17.525 [ZWaveSerialHandler        ] - NODE 255: Sending REQUEST Message = 01 04 00 60 06 9D 
2017-04-23 15:38:24.332 [ZWaveTransactionManager   ] - NODE 74: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@4f0a523c
2017-04-23 15:38:25.654 [ZWaveTransactionManager   ] - NODE 4: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@3ef49baf
2017-04-23 15:39:09.184 [ZWaveTransactionManager   ] - NODE 13: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@37fcd2ed
2017-04-23 15:39:38.655 [ZWaveTransactionManager   ] - NODE 67: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@77f7769c
2017-04-23 15:50:06.238 [ZWaveThingHandler         ] - NODE 2: Polling...
2017-04-23 15:50:06.238 [ZWaveThingHandler         ] - NODE 2: Polling deferred until initialisation complete
2017-04-23 15:50:06.238 [ZWaveThingHandler         ] - NODE 7: Polling...
2017-04-23 15:50:06.238 [ZWaveThingHandler         ] - NODE 7: Polling deferred until initialisation complete
2017-04-23 15:50:06.240 [ZWaveThingHandler         ] - NODE 12: Polling...
2017-04-23 15:50:06.240 [ZWaveThingHandler         ] - NODE 12: Polling deferred until initialisation complete
2017-04-23 15:50:06.241 [ZWaveThingHandler         ] - NODE 11: Polling...

Thank you for the new update. Unfortunately the problem with the Java exception at alarm notifications remains.
I even installed for testing purposes a fresh install with OH210, Snapshot 889 and your new binding (2.1.0.201704231549) and another Z-Wave Gen5 Stick and only one fresh included node. The result is the same:

In Karaf the java exception is thrown:

openhab> java.lang.reflect.InvocationTargetException
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
        at java.lang.reflect.Method.invoke(Unknown Source)
        at org.openhab.binding.zwave.internal.protocol.commandclass.ZWaveCommand
Class.handleApplicationCommandRequest(ZWaveCommandClass.java:245)
        at org.openhab.binding.zwave.internal.protocol.ZWaveNode.processCommand(
ZWaveNode.java:1284)
        at org.openhab.binding.zwave.internal.protocol.ZWaveTransactionManager$Z
WaveReceiveThread.run(ZWaveTransactionManager.java:413)
Caused by: java.lang.NullPointerException
        at org.openhab.binding.zwave.internal.protocol.commandclass.ZWaveAlarmCo
mmandClass.handleNotificationReport(ZWaveAlarmCommandClass.java:140)
        ... 7 more

and in the log (I triggered the alarm at 22:06 for the only node 12):

2017-04-23 22:02:55.845 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction from controllerQueue
2017-04-23 22:02:55.845 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage nothing
2017-04-23 22:06:03.118 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0F 00 04 00 0C 09 71 05 00 00 00 FF 07 08 00 75 
2017-04-23 22:06:03.119 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT 6
2017-04-23 22:06:03.120 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage inputMessage: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=12, callback=0, payload=00 0C 09 71 05 00 00 00 FF 07 08 00 
2017-04-23 22:06:03.120 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lockMessage: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=12, callback=0, payload=00 0C 09 71 05 00 00 00 FF 07 08 00 
2017-04-23 22:06:03.120 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=12, callback=0, payload=00 0C 09 71 05 00 00 00 FF 07 08 00 
2017-04-23 22:06:03.121 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2017-04-23 22:06:03.121 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Application Command Request (ALIVE:REQUEST_NIF)
2017-04-23 22:06:03.121 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: Incoming command class COMMAND_CLASS_ALARM, endpoint 0
2017-04-23 22:06:03.121 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: SECURITY NOT required on COMMAND_CLASS_ALARM
2017-04-23 22:06:03.121 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 12: Received COMMAND_CLASS_ALARM V5 NOTIFICATION_REPORT
2017-04-23 22:06:03.135 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Commands processed 1.
2017-04-23 22:06:03.135 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@471dd04c.
2017-04-23 22:06:03.136 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2017-04-23 22:06:03.136 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2017-04-23 22:06:03.136 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2017-04-23 22:06:03.136 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start
2017-04-23 22:06:03.136 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: listening == false, frequentlyListening == false, awake == false
2017-04-23 22:06:03.136 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Node not awake!
2017-04-23 22:06:03.137 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction from controllerQueue
2017-04-23 22:06:03.137 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage nothing
2017-04-23 22:06:03.219 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 08 0C 03 20 01 FF 2B 
2017-04-23 22:06:03.220 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT 6
2017-04-23 22:06:03.220 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage inputMessage: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=12, callback=8, payload=08 0C 03 20 01 FF 
2017-04-23 22:06:03.220 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lockMessage: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=12, callback=8, payload=08 0C 03 20 01 FF 
2017-04-23 22:06:03.221 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=12, callback=8, payload=08 0C 03 20 01 FF 
2017-04-23 22:06:03.221 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2017-04-23 22:06:03.221 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Application Command Request (ALIVE:REQUEST_NIF)
2017-04-23 22:06:03.222 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: Incoming command class COMMAND_CLASS_BASIC, endpoint 0
2017-04-23 22:06:03.222 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: SECURITY NOT required on COMMAND_CLASS_BASIC
2017-04-23 22:06:03.222 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 12: Received COMMAND_CLASS_BASIC V1 BASIC_SET
2017-04-23 22:06:03.222 [DEBUG] [.commandclass.ZWaveBasicCommandClass] - NODE 12: Basic report, value = 255
2017-04-23 22:06:03.222 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveCommandClassValueEvent
2017-04-23 22:06:03.223 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2017-04-23 22:06:03.223 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Got a value event from Z-Wave network, endpoint = 0, command class = COMMAND_CLASS_BASIC, value = 255
2017-04-23 22:06:03.223 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Updating channel state zwave:device:15970bead83:node12:sensor_binary to ON [OnOffType]
2017-04-23 22:06:03.224 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Commands processed 1.
2017-04-23 22:06:03.224 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@3a0bebc5.
2017-04-23 22:06:03.224 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2017-04-23 22:06:03.224 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2017-04-23 22:06:03.224 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2017-04-23 22:06:03.225 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start
2017-04-23 22:06:03.225 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: listening == false, frequentlyListening == false, awake == false
2017-04-23 22:06:03.225 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Node not awake!
2017-04-23 22:06:03.225 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction from controllerQueue
2017-04-23 22:06:03.225 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage nothing
2017-04-23 22:06:03.234 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 0C 03 20 01 FF 23 
2017-04-23 22:06:03.235 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT 6
2017-04-23 22:06:03.235 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage inputMessage: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=12, callback=0, payload=00 0C 03 20 01 FF 
2017-04-23 22:06:03.235 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lockMessage: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=12, callback=0, payload=00 0C 03 20 01 FF 
2017-04-23 22:06:03.236 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=12, callback=0, payload=00 0C 03 20 01 FF 
2017-04-23 22:06:03.236 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2017-04-23 22:06:03.236 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Application Command Request (ALIVE:REQUEST_NIF)
2017-04-23 22:06:03.236 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: Incoming command class COMMAND_CLASS_BASIC, endpoint 0
2017-04-23 22:06:03.236 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: SECURITY NOT required on COMMAND_CLASS_BASIC
2017-04-23 22:06:03.237 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 12: Received COMMAND_CLASS_BASIC V1 BASIC_SET
2017-04-23 22:06:03.237 [DEBUG] [.commandclass.ZWaveBasicCommandClass] - NODE 12: Basic report, value = 255
2017-04-23 22:06:03.237 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveCommandClassValueEvent
2017-04-23 22:06:03.237 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2017-04-23 22:06:03.237 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Got a value event from Z-Wave network, endpoint = 0, command class = COMMAND_CLASS_BASIC, value = 255
2017-04-23 22:06:03.237 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Updating channel state zwave:device:15970bead83:node12:sensor_binary to ON [OnOffType]
2017-04-23 22:06:03.238 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Commands processed 1.
2017-04-23 22:06:03.239 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@7cbffcf2.
2017-04-23 22:06:03.239 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2017-04-23 22:06:03.239 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2017-04-23 22:06:03.239 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2017-04-23 22:06:03.239 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start
2017-04-23 22:06:03.239 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: listening == false, frequentlyListening == false, awake == false
2017-04-23 22:06:03.240 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Node not awake!
2017-04-23 22:06:03.240 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction from controllerQueue
2017-04-23 22:06:03.240 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage nothing

The same problem occurs not only with the motion sensors, but also with my Door/Window-Sensors (Fibaro FGK101). As soon as an alarm is triggered I get the java exception and no update in OH2. So it looks as if there might be a problem with the alarm notification class?

And one more detail: The problems only start after a restart of OH2. If you include the device for the first time, everything is stable. After shutting down and restarting OH2 the java exceptions start to occur.

Does the binding stop, or just logs? Or the whole system? Not really sure what to say, or even if this is related to ZWave based on this?

Ok - I know what the problem is - thanks for the good feedback. Give me 5 minutes and I’ll post an updated binding which should fix this.

3 minutes and done :wink: Let me know if it solves the problem…

Has anyone successfully securely included a Kwikset 910/914 lock on this binding? I have other locks that are included, but I excluded one in testing. After 30 or more attempts, I cannot get this lock to securely include.

The search button works well ;). I did a search for 914 on this thread and it shows a number of people seem to have included this device…

If there’s a way to completely reset it, then I would suggest this.