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

rgerrans · August 29, 2017, 10:06pm

Will do. Is there an easier way to update the binding in OH once I update it in addons other than a full restart?

chris · August 29, 2017, 10:08pm

You should be able to restart from Karaf without restarting the whole of OH. (uninstall the old one and start the new one).

5iver · August 29, 2017, 10:10pm

This looks to be working now for BE469. These are keypad lock, keypad unlock, keypad lock without code, manual lock, and manual unlock:

Updating channel state zwave:device:07cb40a2:node183:alarm_raw to {"code":"2","type":"ACCESS_CONTROL","event":"5","status":"255"} [StringType]
Updating channel state zwave:device:07cb40a2:node183:alarm_raw to {"code":"2","type":"ACCESS_CONTROL","event":"6","status":"255"} [StringType]
Updating channel state zwave:device:07cb40a2:node183:alarm_raw to {"type":"ACCESS_CONTROL","event":"5","status":"255"} [StringType]
Updating channel state zwave:device:07cb40a2:node183:alarm_raw to {"type":"ACCESS_CONTROL","event":"1","status":"255"} [StringType]
Updating channel state zwave:device:07cb40a2:node183:alarm_raw to {"type":"ACCESS_CONTROL","event":"2","status":"255"} [StringType]

rgerrans · August 29, 2017, 10:10pm

I tried that earlier where I uninstalled the old one and then couldn’t get it to load the new one?

5iver · August 29, 2017, 10:16pm

If the binding names are the same, I have found that just pasting it into addons and overwriting the old one is enough.

chris · August 29, 2017, 10:16pm

I’ve made another small update for the notification processing and added the notification name as well which might be of use.

rgerrans · August 29, 2017, 10:17pm

Good to know, thanks.

5iver · August 29, 2017, 10:18pm

I’ve dropped it in and I’m waiting for everything to settle. Nonce failure rate is very high when everything is chatting.

2017-08-29 18:06:17.945 [ZWaveNode                 ] - NODE 183: Decapsulating COMMAND_CLASS_SECURITY
2017-08-29 18:06:17.945 [ZWaveSecurityCommandClass ] - NODE 183: SECURITY_ERR No valid NONCE! null

rgerrans · August 29, 2017, 10:31pm

Everything on my side works great. I can get both the alarm codes and the alarm level from the json.

Thanks!!! More beer money on it’s way soon.

chris · August 29, 2017, 10:34pm

Great stuff - I’m glad it’s working .

chris · August 29, 2017, 10:35pm

Maybe it’s a timing issue if there’s a lot going on - I’m not sure from this though. Nonces are only valid for a few seconds after which they are invalid and can’t be used.

rgerrans · August 29, 2017, 10:35pm

My old Vera went out in the mail yesterday to a new owner

5iver · August 29, 2017, 11:06pm

Maybe it was intentional, but it looks like there is an extra underscore in the notification value. I got the lock to report jammed by only partially locking it. And I don’t recall ever getting a Forced Entry alarm to show up (pounded on the door)! But it also then set alarm_number to 2, which I had been using as an unlock. Hmmm… time for a rewrite.

NODE 183: Updating channel state zwave:device:07cb40a2:node183:alarm_raw to {"notification":"ACCESS__MANUAL_LOCK","type":"ACCESS_CONTROL","event":"1","status":"255"} [StringType]
NODE 183: Updating channel state zwave:device:07cb40a2:node183:alarm_raw to {"notification":"ACCESS__MANUAL_UNLOCK","type":"ACCESS_CONTROL","event":"2","status":"255"} [StringType]
NODE 183: Updating channel state zwave:device:07cb40a2:node183:alarm_raw to {"notification":"ACCESS__KEYPAD_LOCK","code":"1","type":"ACCESS_CONTROL","event":"5","status":"255"} [StringType]
NODE 183: Updating channel state zwave:device:07cb40a2:node183:alarm_raw to {"notification":"ACCESS__KEYPAD_UNLOCK","code":"1","type":"ACCESS_CONTROL","event":"6","status":"255"} [StringType]
NODE 183: Updating channel state zwave:device:07cb40a2:node183:alarm_raw to {"notification":"ACCESS__LOCK_JAMMED","type":"ACCESS_CONTROL","event":"11","status":"255"} [StringType]
NODE 183: Updating channel state zwave:device:07cb40a2:node183:alarm_raw to {"notification":"ACCESS__KEYPAD_LOCK","type":"ACCESS_CONTROL","event":"5","status":"255"} [StringType]
NODE 183: Updating channel state zwave:device:07cb40a2:node183:alarm_raw to {"notification":"BURGLAR__TAMPER_UNKNOWN","type":"BURGLAR","event":"2","status":"255"} [StringType]

mcqwerty · August 30, 2017, 2:36am

I don’t think it is a problem with your code. I have had this same issue for a while: Schlage BE469 - Zwave binding with security - missing features you even replied

chris · August 30, 2017, 7:01am

Yes - this was the intention. It breaks up the notification and the event (ie notification type is ACCESS, and the event is MANUAL_LOCK).

It is true that this makes is slightly different than the type in the “type” field which is a bit annoying and I might revisit this. When I defined these event types a few months back I wanted to avoid making them reeeaaaalllyyyy long so truncated things like ACCESS_CONTROL down to ACCESS

chris · August 30, 2017, 7:33am

Just to be clear - I guess that this is just how the lock works right?

mstormi · August 30, 2017, 4:09pm

I keep seeing a number of these exceptions running snapshot #1025 and version 2.1.0.201708272249 of your new binding. Causing message is quoted at the top of the log.
network_xxxxxxxx__node_42.xml (2.4 KB)
jsondb-excerpt-node42.xml (5.7 KB, not really XML but the node 42 definition in jsondb)

2017-08-30 17:52:11.266 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0D 00 04 00 2A 07 56 01 30 03 FF D1 CB 5A
2017-08-30 17:52:11.272 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT 6
2017-08-30 17:52:11.278 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=42, callback=0, payload=00 2A 07 56 01 30 03 FF D1 CB
2017-08-30 17:52:11.282 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lock Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=42, callback=0, payload=00 2A 07 56 01 30 03 FF D1 CB
2017-08-30 17:52:11.287 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=42, callback=0, payload=00 2A 07 56 01 30 03 FF D1 CB
2017-08-30 17:52:11.289 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2017-08-30 17:52:11.291 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 42: Application Command Request (ALIVE:REQUEST_NIF)
2017-08-30 17:52:11.293 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 42: Decapsulating COMMAND_CLASS_CRC_16_ENCAP
2017-08-30 17:52:11.295 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 42: COMMAND_CLASS_CRC_16_ENCAP not found
2017-08-30 17:52:11.297 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2017-08-30 17:52:11.299 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start
2017-08-30 17:52:11.300 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 49: listening == false, frequentlyListening == false, awake == false
2017-08-30 17:52:11.302 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 49: Node not awake!
2017-08-30 17:52:11.304 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 90: listening == false, frequentlyListening == false, awake == false
2017-08-30 17:52:11.305 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 90: Node not awake!
2017-08-30 17:52:11.307 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 42: listening == false, frequentlyListening == false, awake == false
2017-08-30 17:52:11.309 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 42: Node not awake!
2017-08-30 17:52:11.310 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction from controllerQueue
2017-08-30 17:52:11.312 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage nothing
2017-08-30 17:52:11.352 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 2A 03 60 0D 01 B7
2017-08-30 17:52:11.383 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT 6
2017-08-30 17:52:11.386 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=42, callback=0, payload=00 2A 03 60 0D 01
2017-08-30 17:52:11.389 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lock Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=42, callback=0, payload=00 2A 03 60 0D 01
2017-08-30 17:52:11.392 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=42, callback=0, payload=00 2A 03 60 0D 01
2017-08-30 17:52:11.394 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2017-08-30 17:52:11.395 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 42: Application Command Request (ALIVE:REQUEST_NIF)
2017-08-30 17:52:11.397 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 42: Decapsulating COMMAND_CLASS_MULTI_CHANNEL
2017-08-30 17:52:11.400 [ERROR] [nal.protocol.ZWaveTransactionManager] - Exception processing frame: Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=42, callback=0, payload=00 2A 03 60 0D 01
2017-08-30 17:52:11.401 [ERROR] [nal.protocol.ZWaveTransactionManager] - Exception processing frame:
java.lang.ArrayIndexOutOfBoundsException: 3
        at org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload.getPayloadByte(ZWaveCommandClassPayload.java:49) [208:org.openhab.binding.zwave:2.1.0.201708272249]
        at org.openhab.binding.zwave.internal.protocol.commandclass.ZWaveMultiInstanceCommandClass.getSourceEndpoint(ZWaveMultiInstanceCommandClass.java:381) [208:org.openhab.binding.zwave:2.1.0.201708272249]
        at org.openhab.binding.zwave.internal.protocol.ZWaveNode.processCommand(ZWaveNode.java:1207) [208:org.openhab.binding.zwave:2.1.0.201708272249]
        at org.openhab.binding.zwave.internal.protocol.ZWaveTransactionManager$ZWaveReceiveThread.run(ZWaveTransactionManager.java:421) [208:org.openhab.binding.zwave:2.1.0.201708272249]

chris · August 30, 2017, 4:14pm

This is a corrupt frame coming from node 42. The error is simply saying it’s a corrupt frame with no data received. I ca change the error, but it will still be corrupt unfortunately.

mstormi · August 30, 2017, 4:22pm

Ok, thanks … now since it’s a pretty standard node (Fibaro FGMS) that has been working well for a long time (IIRC, it’s producing errors with the standard binding, too, but the message is different) , and short of the possibility to obtain a firmware update, is there anything I can do except to ignore it ? Does the message give you a hint w.r.t. an invalid parameter setting or some such ?

chris · August 30, 2017, 4:29pm

Yes - the different bindings can log different errors - they are quite different.

The only thing I can think of is to reset it. First I would try removing the power (battery) and see if that helps. If not, you might need to exclude it.

No - it’s a multichannel encapsulation message with no data inside

The above part of the message is -:
60 = multichannel command class
0D = encapsulation
01 = source endpoint

This should be followed by the destination endpoint, and the actual encapsulated data.