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

The log is badly formatted for some reason so I can’t read it. It also only contains the encrypted information, so isn’t useful for debugging, although I also wouldn’t recommend publishing secure logs here anyway.

While I agree putting the secure logs in the thread is not ideal, this is a
test system so once I get the locks working as expected, I will be starting
fresh with a new system and reset controller etc…, including a new Network
Security Key.

So I see there were spaces in my cut and paste from the terminal which I
suspect it from the line wraps. I have fixed them and run them through
your log viewer with the following results. These logs simply show what
happens when manually unlocking the door.

08:36:01.413 2 RX REQ ApplicationCommandHandler SECURITY[#NUM!]
08:36:01.419 2 TX REQ SendData 105 SECURITY_NONCE_REPORT NONCE ID 242 ACK
AUTO_ROUTE EXPLORE
08:36:01.423 RX ACK
08:36:01.449 2 RX RES SendData 105 ACCEPTED BY CONTROLLER

If there is a better way or something else I can do to get you what you
require, just let me know… I am glad to help resolve the issues if I can.

Chris, if you remember I previously mentioned my BE369 needed many attempts to include also. The delay issue sounds reasonably like the problem. I’m sorry I didn’t pull any logs at the time, but it was certainly a lot of try and try again till it suddenly just “worked” for no apparent reason.

Interesting. @dbadia do I recall seeing something in the past that some lock (maybe this one?) needed some sort of delay after initial inclusion, but before secure inclusion started? Timing is rather tight during this phase so I’m a bit hesitant to add too much delay, but maybe there’s a need for some sort of delay on this lock?

Hmm, I don’t remember anything specific, but it has been awhile. As I recall, the handshake order is pretty well defined.

I have a couple of devices that aren’t in the OH2 database (per http://www.cd-jackson.com/index.php/zwave/zwave-device-database/zwave-device-list) so I went to add them. But where would I get the type:id IDs from? I can’t find them in the log during the pairing process. Is there some other way to get them?

Thanks
Dave

You can always just type in the item name?

If HABmin doesn’t supply a default name, this almost certainly means that an item with the default name already exists. Since the item exists, HABmin doesn’t offer a default as it assumes that if you’re adding a second item to this channel, then you need to define the name yourself.

I did try typing in a name, but then I saw a pop up error message stating that a 404 error occurred (looks like the REST call failed with my made up name)

It was in reference to Python saying that he edited the XML in the .jar.

I dug through my OH2 set up and found some old channel links. Deleted them and should be good now

I accidentally set off my smoke alarm last night and unfortunately, it looks like those devices aren’t communicating correctly with the new binding.

They are ZCOMBOs and so are already a pain in the ass and require you to wake them up several times during initialization, the battery level reports seem to work correctly:

14:07:09.577 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 2D 03 80 03 59 06
14:07:09.579 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT 6
14:07:09.579 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage inputMessage: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=45, callback=0, payload=00 2D 03 80 03 59
14:07:09.579 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lockMessage: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=45, callback=0, payload=00 2D 03 80 03 59
14:07:09.579 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=45, callback=0, payload=00 2D 03 80 03 59
14:07:09.579 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
14:07:09.579 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 45: Application Command Request (ALIVE:DYNAMIC_VALUES)
14:07:09.579 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 45: Incoming command class COMMAND_CLASS_BATTERY, endpoint 0
14:07:09.579 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 45: SECURITY not supported
14:07:09.579 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 45: Received COMMAND_CLASS_BATTERY V1 BATTERY_REPORT
14:07:09.580 [DEBUG] [ommandclass.ZWaveBatteryCommandClass] - NODE 45: Battery report value = 89
14:07:09.580 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveCommandClassValueEvent
14:07:09.580 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 45: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
14:07:09.580 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 45: Got a value event from Z-Wave network, endpoint = 0, command class = COMMAND_CLASS_BATTERY, value = 89
14:07:09.580 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 45: Updating channel state zwave:device:027c523a:node45:battery-level to 89 [DecimalType]
14:07:09.582 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 45: Commands processed 1.
14:07:09.583 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 45: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@575632ec.
14:07:09.583 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
14:07:09.583 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
14:07:09.583 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
14:07:09.583 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start

but if I trigger the alarm or the heartbeat goes in, I get this:

14:09:07.137 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'AlarmBasement_Heartbeat-zwave:device:027c523a:node45:alarm_general' has been added.
14:09:16.455 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'AlarmBasement_Alarm-zwave:device:027c523a:node45:alarm_smoke' has been added.
14:09:56.029 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0A 00 04 00 2D 04 71 05 0C FF 5F
14:09:56.030 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT 6
14:09:56.030 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage inputMessage: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=45, callback=0, payload=00 2D 04 71 05 0C FF
14:09:56.030 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lockMessage: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=45, callback=0, payload=00 2D 04 71 05 0C FF
14:09:56.030 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=45, callback=0, payload=00 2D 04 71 05 0C FF
14:09:56.030 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
14:09:56.030 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 45: Application Command Request (ALIVE:DYNAMIC_VALUES)
14:09:56.030 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 45: Incoming command class COMMAND_CLASS_ALARM, endpoint 0
14:09:56.030 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 45: SECURITY not supported
14:09:56.030 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 45: Received COMMAND_CLASS_ALARM V1 NOTIFICATION_REPORT
14:09:56.031 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 45: Commands processed 1.
14:09:56.031 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 45: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@772dbf8b.
14:09:56.031 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
14:09:56.031 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
14:09:56.031 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
14:09:56.031 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start

I re-linked the channel to make sure that was set up correctly before triggering the alarm but it doesn’t seem to map the ALARM message to the channel.

Normally they will show up in the attributes section of the thing in HABmin.

I don’t see anything wrong with the processing of the message. I just added some tests to test this and it seems to process just fine with the message from the ZCombo.

However, something doesn’t look right as the message doesn’t appear to be processed. However, from the log entries I see, I can’t see how this is possible for there not to be another entry logged unless there was an exception thrown that exited the processing early. From my test, it looks fine - the message should be processed, so we need to see if there is an exception and catch it.

Hello,

I switched the version today and now i have in these message in my Console.

java.lang.reflect.InvocationTargetException
at sun.reflect.GeneratedMethodAccessor69.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.openhab.binding.zwave.internal.protocol.commandclass.ZWaveCommandClass.handleApplicationCommandRequest(ZWaveCommandClass.java:245)
at org.openhab.binding.zwave.internal.protocol.ZWaveNode.processCommand(ZWaveNode.java:1284)
at org.openhab.binding.zwave.internal.protocol.ZWaveTransactionManager$ZWaveReceiveThread.run(ZWaveTransactionManager.java:413)
Caused by: java.lang.NullPointerException
at org.openhab.binding.zwave.internal.protocol.commandclass.ZWaveAlarmCommandClass.handleNotificationReport(ZWaveAlarmCommandClass.java:140)
… 6 more

I will only inform you. All works fine!!

Ah Java is 1.8.0_131 i dont know if this is my Problem.

Thank you for the Binding it works with all my Devices!!!

Hmm, it’s showing blank for me.

Full log from the inclusion is here: https://pastebin.com/raw/6XHUkz8C

I’m still using the april build, should I upgrade to the latest?

Cool I’ll try it out, is there a .jar to get?

Hi there,
my device Popp 012501 shows in the attribute section in habmin a questionmark at “using security”. What is the message? security “yes” or “no” or “don’t know”?

How can i enable security?
I use the actual snapshot of OH2.

My device is not working - is this the reason why?

Thanks - Karl Heinz

The question mark means it doesn’t know. This probably means you’re running a binding that does not support security.

It is enabled in this development binding.

Security is not enabled in the snapshot - this will explain why it doesn’t work ;).

It seems you need to install the development version if you want to use security. Please read the top of this thread on how to install it.

Hi Chris!
Thanks for your help - i did it like this:

- Delete all Zwave Things from Habmin.
- Uninstall the Zwave binding from Habmin. - You will NOT reinstall it.
- Stop OH2
- Copy the JAR file to your /usr/share/openhab2/addons folder.
- Start OH2.
- log into Karaf ie… ssh openhab@localhost -p 8101 password is habopen
- Start the zwave binding with: bundle:start org.openhab.binding.zwave
- If get an error, you need to install the serial binding first: feature:install openhab-transport-serial
- Now got back to Habmin, and Readd a Zwave Controller. Do NOT re-install the 2.0 Zwave Binding.
- Set your USB port and rescan for devices.

My POPP 012501 has now a “no” at “Using Secure - Sicherheit verwenden”.

What is to do with the security key in the config of the Z-Wave Serial Controller?
The Controler is configured to use Secure with Entry Control Devices.
Do i hat to reinclude the Popp-Device?

Thanks for your help!
Karl Heinz

Yes - secure inclusion MUST be done within 15 seconds of the main inclusion, so if this wasn’t done, you need to exclude the device and re-include it.

I try it this evening. Have a good day!

Is status “initializing” the expected status for an item after switching to development build?
I did not exclude/re-include the device after enabling the development build.

Also just for clarification is this development build by chance supporting venetian blinds for Fibaro FGRM222 Roller Shutter?

Thanks

No - probably this means there is a problem.

But did you delete all things and add them back again? This is needed.