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

[MrWendal (Steve)]

@5iver

Hmmm,… so, with the development binding, in the logs you can see the SCENE_ACTIVATION command class report come in, but there is no channel listed for scene_number. What do you see in the device’s xml (in userdata/zwave) for manufacturer, deviceId, deviceType, and is SCENE_ACTIVATION listed under NIF and endpoint 0? Of course, you’d need to be back on the dev version to check this.

Out of curiosity, did you try restarting OH?

I’ve been doing some more checking and it might be related to security, as I’ve tried starting afresh with 2.2, dev - no security option set and dev security all devices set. I’ve been deleting Things, excluding devices, restarting OH2 between each test. I can’t see the scene channel in any cases with the dev version.

In 2.2 xml file I see:

• manufacturer = 0x10f, deviceId = 0x1000, deviceType = 0x102.
• commandClass = SCENE_ACTIVATION

In dev xml file’s I see:

• manufacturer = 0x10f, deviceId = 0x1000, deviceType = 0x102.
• COMMAND_CLASS_SCENE_ACTIVATION in endpoint 0 if I’ve read the nesting correctly…

I can’t see NIF in mentioned in the xml files - is there a different term I should be checking for?

Thanks,
Steve.

[chris (Chris Jackson)]

@MrWendal

I can’t see NIF in mentioned in the xml files - is there a different term I should be checking for?

I think it’s called nodeInformationFrame in the XML.

[5iver (Scott Rushworth)]

@MrWendal

manufacturer = 0x10f, deviceId = 0x1000, deviceType = 0x102.

The device is being identified correctly…

@MrWendal

COMMAND_CLASS_SCENE_ACTIVATION in endpoint 0

… and reporting the SCENE_ACTIVATION CC.

@MrWendal

I can’t see NIF in mentioned in the xml files

Sorry, I used the acronym… <nodeInformationFrame>

@MrWendal

I can’t see the scene channel in any cases with the dev version.

Where have you looked…item values, Habmin, PaperUI, logs, etc.?

[MrWendal (Steve)]

@5iver

Sorry, I used the acronym… <nodeInformationFrame>

No problem. COMMAND_CLASS_SCENE_ACTIVATION is not listed in <nodeInformationFrame>, it is only listed in <endpoints>.

@5iver

Where have you looked…item values, Habmin, PaperUI, logs, etc.?

Yes, all of them, and the exported items in VSCode as well. “Scene Number” is listed as a channel in 2.2, and there is no mention of it in the dev binding in Habmin for example. I also see a different number of channels between 2.2 (14 channels) and dev (15 channels) in Habmin as well.

Thanks,
Steve.

[5iver (Scott Rushworth)]

I think I see the issue. There was an update in the database on March 10, and I’m guessing that was the addition of the scene_number channel because it is not in here. It could have been another update though. @mhilbush or @chris might be able to confirm this. You’ll need to wait for the next binding update to come out and hopefully scene_number will turn up.

[mhilbush (Mark)]

Yesterday I updated config params 6 and 8. I changed the min from 1 to 0 as discussed here.

[5iver (Scott Rushworth)]

Found it… there was an update on March 8 to add SCENE_ACTIVATION, which explains why it is not in the current binding. A view of the history in the database would be handy!

[chris (Chris Jackson)]

@5iver

A view of the history in the database would be handy!

The full history of the published database is on Github, but of course that’s not quite what you’re after, and that’s a bit more difficult unfortunately…

I’m doing some restructuring of the database at the moment - once this is done I’ll publish a new dev binding.

[MrWendal (Steve)]

@chris

I’m doing some restructuring of the database at the moment - once this is done I’ll publish a new dev binding.

Excellent, I’ll keep an eye open for the updated binding and let you know how it goes.

Thanks,
Steve.

[chris (Chris Jackson)]

I’ve just updated the binding. This has a complete resynchronisation of the database, and some restructuring to put all the devices into folders based on manufacturer. The database now has 713 live entries (and probably another 50 or 60 partially complete devices) so this should make things a bit more usable.

[MrWendal (Steve)]

@chris

I’ve just updated the binding. This has a complete resynchronisation of the database, and some restructuring to put all the devices into folders based on manufacturer. The database now has 713 live entries (and probably another 50 or 60 partially complete devices) so this should make things a bit more usable.

I’ve just tried the updated binding and the scene number channel is now working for the Fibaro FGD212 dimmer.

Many thanks for your help!
Steve.

[gmeks]

Im getting this after updating to 11th March 2018.

    2018-03-12 21:47:52.778 [ERROR] [mmandclass.ZWaveSecurityCommandClass] - NODE 28: Error decapsulating security message

    java.security.InvalidKeyException: No installed provider supports this key: (null)

    	at javax.crypto.Cipher.chooseProvider(Cipher.java:893) [?:?]

    	at javax.crypto.Cipher.init(Cipher.java:1249) [?:?]

    	at javax.crypto.Cipher.init(Cipher.java:1186) [?:?]

    	at org.openhab.binding.zwave.internal.protocol.commandclass.ZWaveSecurityCommandClass.generateMAC(ZWaveSecurityCommandClass.java:501) [223:org.openhab.binding.zwave:2.3.0.201803111809]

    	at org.openhab.binding.zwave.internal.protocol.commandclass.ZWaveSecurityCommandClass.getSecurityMessageDecapsulation(ZWaveSecurityCommandClass.java:303) [223:org.openhab.binding.zwave:2.3.0.201803111809]

    	at org.openhab.binding.zwave.internal.protocol.ZWaveNode.processCommand(ZWaveNode.java:1170) [223:org.openhab.binding.zwave:2.3.0.201803111809]

    	at org.openhab.binding.zwave.internal.protocol.ZWaveTransactionManager$ZWaveReceiveThread.run(ZWaveTransactionManager.java:440) [223:org.openhab.binding.zwave:2.3.0.201803111809]

Its a PSP05 Motion Sensor
Other secure devices seem to work just fine

[Marco_Goncalves]

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]

And in the attributes, it have the following look

[chris (Chris Jackson)]

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.

[dbadia]

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).

Here is my config:

Switch DoorLock_Back_Door 			<lockdy> 			(gDoorLocks, gIndoor)  {channel="zwave:device:15bfa0704b9:node10:lock_door"}
Switch item=DoorLock_Back_Door label="Deck Door Lock"

Dave

[gmeks]

Seems my previus error was solved by reboot. Almost like i need to reboot ophab after updating the binding ?

Posting incase others did the same dump thing

[dbadia]

@chris the codebase for this thread, is it the development branch?
Would like to submit a PR for minor logging issue I see in my logs

[chris (Chris Jackson)]

@dbadia

@chris the codebase for this thread, is it the development branch?

Would like to submit a PR for minor logging issue I see in my logs

Hi Dave,
Yes, that’s correct - please feel free to submit any PR .

Cheers
Chris

[Clinton_Johnson]

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

I am using a Z-Stick Gen5

2018-03-15 21:12:26.072 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:1622c7d4dc8' changed from ONLINE to OFFLINE (BRIDGE_OFFLINE): Controller is offline

==> /var/log/openhab2/openhab.log <==

2018-03-15 21:12:26.087 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Serial port is initialized

2018-03-15 21:12:26.123 [INFO ] [ve.internal.protocol.ZWaveController] - Starting ZWave controller

2018-03-15 21:12:26.127 [INFO ] [ve.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false.

2018-03-15 21:12:29.348 [INFO ] [age.SerialApiGetInitDataMessageClass] - NODE 1: Node found

2018-03-15 21:12:29.352 [INFO ] [age.SerialApiGetInitDataMessageClass] - ZWave Controller using Controller API

2018-03-15 21:12:29.355 [INFO ] [age.SerialApiGetInitDataMessageClass] - ZWave Controller is Primary Controller

2018-03-15 21:12:29.361 [INFO ] [age.SerialApiGetInitDataMessageClass] - ------------Number of Nodes Found Registered to ZWave Controller------------

2018-03-15 21:12:29.364 [INFO ] [age.SerialApiGetInitDataMessageClass] - # Nodes = 1

2018-03-15 21:12:29.367 [INFO ] [age.SerialApiGetInitDataMessageClass] - ----------------------------------------------------------------------------

==> /var/log/openhab2/events.log <==

2018-03-15 21:12:29.469 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:1622c7d4dc8' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE

2018-03-15 21:12:29.493 [me.event.ThingUpdatedEvent] - Thing 'zwave:serial_zstick:1622c7d4dc8' has been updated.

2018-03-15 21:12:35.767 [arthome.event.BindingEvent] - org.openhab.binding.zwave.event.BindingEvent@210e50

==> /var/log/openhab2/openhab.log <==

2018-03-15 21:12:51.846 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zwave:device:1622c7d4dc8:node9' to inbox.

==> /var/log/openhab2/events.log <==

2018-03-15 21:12:51.848 [home.event.InboxAddedEvent] - Discovery Result with UID 'zwave:device:1622c7d4dc8:node9' has been added.

2018-03-15 21:12:51.854 [arthome.event.BindingEvent] - org.openhab.binding.zwave.event.BindingEvent@e6f3e4

2018-03-15 21:13:09.959 [me.event.InboxRemovedEvent] - Discovery Result with UID 'zwave:device:1622c7d4dc8:node9' has been removed.

2018-03-15 21:13:10.024 [hingStatusInfoChangedEvent] - 'zwave:device:1622c7d4dc8:node9' changed from UNINITIALIZED to INITIALIZING

2018-03-15 21:13:10.031 [hingStatusInfoChangedEvent] - 'zwave:device:1622c7d4dc8:node9' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2018-03-15 21:13:10.047 [hingStatusInfoChangedEvent] - 'zwave:device:1622c7d4dc8:node9' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE

2018-03-15 21:13:10.056 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:1622c7d4dc8:node9' has been updated.

2018-03-15 21:13:10.060 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:1622c7d4dc8:node9' has been updated.

==> /var/log/openhab2/openhab.log <==

2018-03-15 21:13:18.047 [INFO ] [alization.ZWaveNodeInitStageAdvancer] - NODE 9: SECURITY_INC State=FAILED, Reason=GET_SCHEME

==> /var/log/openhab2/events.log <==

2018-03-15 21:13:18.048 [arthome.event.BindingEvent] - org.openhab.binding.zwave.event.BindingEvent@1fefee

2018-03-15 21:13:18.478 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:1622c7d4dc8:node9' has been updated.

2018-03-15 21:13:18.558 [hingStatusInfoChangedEvent] - 'zwave:device:1622c7d4dc8:node9' changed from ONLINE to UNINITIALIZED

2018-03-15 21:13:18.578 [arthome.event.BindingEvent] - org.openhab.binding.zwave.event.BindingEvent@126c82

2018-03-15 21:13:18.627 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:1622c7d4dc8:node9' has been updated.

2018-03-15 21:13:18.657 [hingStatusInfoChangedEvent] - 'zwave:device:1622c7d4dc8:node9' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)

2018-03-15 21:13:18.684 [hingStatusInfoChangedEvent] - 'zwave:device:1622c7d4dc8:node9' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2018-03-15 21:13:18.689 [hingStatusInfoChangedEvent] - 'zwave:device:1622c7d4dc8:node9' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2018-03-15 21:13:18.692 [hingStatusInfoChangedEvent] - 'zwave:device:1622c7d4dc8:node9' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE

2018-03-15 21:13:18.711 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:1622c7d4dc8:node9' has been updated.

2018-03-15 21:13:19.203 [arthome.event.BindingEvent] - org.openhab.binding.zwave.event.BindingEvent@19e9740

2018-03-15 21:13:19.217 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:1622c7d4dc8:node9' has been updated.

[5iver (Scott Rushworth)]

@Clinton_Johnson

Inclusion = High Power Inclusion

Unless you have a reason for this, go with NWI. Shouldn’t affect the lock though.

@Clinton_Johnson

Security inclusion mode = all devices

Unless you have a reason for this, go with Entry Control Devices. This won’t affect the lock either.

@Clinton_Johnson

I have reset the Lock and reinstalled openhab

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?