When I try to include a Fibaro FGS-223 it throws an exception in the log
2018-03-13 08:51:40.462 [INFO ] [mmandclass.ZWaveSecurityCommandClass] - NODE 9: setupNetworkKey useSchemeZero=false
2018-03-13 08:51:40.544 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zwave:device:controller:node9' to inbox.
2018-03-13 08:51:53.744 [ERROR] [ve.internal.protocol.ZWaveController] - Exception during ZWave thread: Input 2. {}
java.lang.ArrayIndexOutOfBoundsException: 3
at org.openhab.binding.zwave.internal.protocol.commandclass.ZWaveSecurityCommandClass.isSecurityNonceReportMessage(ZWaveSecurityCommandClass.java:1067) [211:org.openhab.binding.zwave:2.3.0.201803101457]
at org.openhab.binding.zwave.internal.protocol.SerialMessage$SerialMessageComparator.compare(SerialMessage.java:692) [211:org.openhab.binding.zwave:2.3.0.201803101457]
at org.openhab.binding.zwave.internal.protocol.SerialMessage$SerialMessageComparator.compare(SerialMessage.java:1) [211:org.openhab.binding.zwave:2.3.0.201803101457]
at java.util.concurrent.PriorityBlockingQueue.siftUpUsingComparator(Unknown Source) [?:?]
at java.util.concurrent.PriorityBlockingQueue.offer(Unknown Source) [?:?]
at java.util.concurrent.PriorityBlockingQueue.add(Unknown Source) [?:?]
at org.openhab.binding.zwave.internal.protocol.ZWaveController.enqueue(ZWaveController.java:546) [211:org.openhab.binding.zwave:2.3.0.201803101457]
at org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer.sendMessage(ZWaveNodeInitStageAdvancer.java:260) [211:org.openhab.binding.zwave:2.3.0.201803101457]
at org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer.addToQueue(ZWaveNodeInitStageAdvancer.java:1170) [211:org.openhab.binding.zwave:2.3.0.201803101457]
at org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer.advanceNodeStage(ZWaveNodeInitStageAdvancer.java:1082) [211:org.openhab.binding.zwave:2.3.0.201803101457]
at org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer.handleNodeQueue(ZWaveNodeInitStageAdvancer.java:230) [211:org.openhab.binding.zwave:2.3.0.201803101457]
at org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer.ZWaveIncomingEvent(ZWaveNodeInitStageAdvancer.java:1306) [211:org.openhab.binding.zwave:2.3.0.201803101457]
at org.openhab.binding.zwave.internal.protocol.ZWaveController.notifyEventListeners(ZWaveController.java:567) [211:org.openhab.binding.zwave:2.3.0.201803101457]
at org.openhab.binding.zwave.internal.protocol.ZWaveController.handleIncomingRequestMessage(ZWaveController.java:250) [211:org.openhab.binding.zwave:2.3.0.201803101457]
at org.openhab.binding.zwave.internal.protocol.ZWaveController.handleIncomingMessage(ZWaveController.java:214) [211:org.openhab.binding.zwave:2.3.0.201803101457]
at org.openhab.binding.zwave.internal.protocol.ZWaveController.access$7(ZWaveController.java:208) [211:org.openhab.binding.zwave:2.3.0.201803101457]
at org.openhab.binding.zwave.internal.protocol.ZWaveController$ZWaveInputThread.run(ZWaveController.java:1324) [211:org.openhab.binding.zwave:2.3.0.201803101457]
This is normally caused by a corrupt frame received from the device - or at least a frame that is not what the binding expects. Possibly it’s an invalid Nonce, but that’s just a guess and I’d need to see a debug log showing the received frame to say more.
Those with kwikset door locks: Does anyone have the current status (locked vs unlocked) reporting reliably in OH? I find mine is typically incorrect, even when soley using OH to lock/unlock (that is, no one has manually changed it’s state).
Hey!!
NOOB here looking for some help. I have tried everything I have found in the 2590 post before me to get a Schlage BE469WK setup but for the life of me i keep getting “NODE 9: SECURITY_INC State=FAILED, Reason=GET_SCHEME”
I have done the following
Inclusion = High Power Inclusion
Security inclusion mode = all devices
Network Key = is set
I have reset the Lock and reinstalled openhab
Unless you have a reason for this, go with NWI. Shouldn’t affect the lock though.
Unless you have a reason for this, go with Entry Control Devices. This won’t affect the lock either.
It looks as though you’re not logging the zwave binding in debug mode, which might help in troubleshooting. Have you been excluding the lock between attempts? Are you running inclusion through OH, with the lock close to the controller?
Hey 5iver!
thanks for the reply! I dont fully understand how to turn on the debug mode. Can you point me some were I can read about it and how to do it? As for excluding it, each time yes.
Also thank you i will switch back to NWI and Entry Control Devices
This log doesn’t include the discovery of the device. Assuming you did another inclusion, does the lock show as Using Security in Habmin, under Attributes?
This is a very interesting log (thanks ). I need to understand it better, but there are some delays following the inclusion that probably are too long, and this is probably screwing up the secure inclusion.
Secure inclusion needs to happen within a number of seconds of the initial inclusion (10 to 15). There is at least a 10 second delay here, so at best we’re border line.
It looks to me like the stick is not responding as I’m expecting to the “end inclusion mode” command, and this is causing the delay. I need to have a look to see if there’s a better way to handle this - I could probably (safely) change this to not wait for the response from the stick, although maybe that causes other issues…
I’ll have a think about this over the next day or so and probably propose a change.
As a matter of interest, what stick do you have? You said “Z-Stick Gen 5”, but I’m not sure what manufacturer that means as there are a lot of Gen 5 sticks out there…
@Clinton_Johnson can you provide another log please - same sort of thing as before. I’d like to see if the same thing happens.
Also, please provide the raw log - something is truncating lines in the log that you provided earlier, so long lines are all uniform length with a $ on the end and I loose a lot of information.
Ok, so don’t worry about another log right now. I’ll post an update at some point today - let’s see if it solves the issue.
I’m not 100% sure why I don’t see this issue with every inclusion, but there is a transaction matching issue at the end of the inclusion. This wastes 10 seconds and I guess different devices implement the security timeout slightly differently and 10 seconds may, or may not, work.
Hopefully I’ve fixed this now and it will be a bit more deterministic!
Can you elaborate a bit about inclusion time of the controller?
On your website it is said that inclusion duration is about 30 seconds (at least this is what I understood).
However, when I look at my stick (Z-Wave USB Stick (ZMEEUZB1)) the blue lamp only starts flashing after 20 seconds of pressing the discover-icon in habmin and then continues for about 10 seconds only…
What I notice is that exactly at the time when the blue led starts blink the green notification on habmin appears telling that the “inclusion has started” and the next green notification telling about “inclusion has ended” is in sync with the ending of the blue blinking.
So that leads me to the thinking that inclusion only happens for a time of 10 seconds which is a very short time frame to be successful especially with devices that are on battery.
Here are the filtered logs of the inclusion controller which point into the same direction:
2018-03-17 14:53:52.460 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeSent, new event IncludeStart
2018-03-17 14:54:03.047 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller stopping inclusion at IncludeStart
2018-03-17 14:54:03.050 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode.
2018-03-17 14:54:03.259 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveInclusionEvent
2018-03-17 14:54:03.273 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 32: Got an event from Z-Wave network: ZWaveInclusionEvent
2018-03-17 14:54:03.276 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeDone, new event IncludeDone
2018-03-17 14:54:03.282 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode.
2018-03-17 14:54:03.300 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller end exclusion
The background is that I try to include a “sensitive strip” which alone takes about 10 seconds to wake up, so the overlap might be my issue.
When the controller is put into inclusion mode, it stays there for 30 seconds. The secure inclusion time is a different time - once a device is included, it has around 10 to 15 seconds to complete the secure inclusion (basically the key exchange) - after this, it’s impossible to securely use the device.
I have no idea about the flashing LEDs, but the inclusion timer is 30 seconds - not 10 seconds.
Please don’t filter the logs - I have no idea what is going on without the full log. It’s probable that something else was happening that blocked the start command being sent even though the timer was started. I really have no clue though without the logs - sorry.
.