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

security
zwave
Tags: #<Tag:0x00007f6ce57cd180> #<Tag:0x00007f6ce57cd018>

(Shorty707) #2351

I want to give a small update on this issue.
10days ago I had 3 devices that are actually communicating with the controller but are marked as FAILED by the controller.
As described when they send something Habmin lists them as online and instantly afterwards get the “isFailed” information and set them to Offline again.

For two devices I found a solution now. In a regular “Heal” these devices were probably skipped as they were listed as Offline.
I started a manual heal on them while I manually did wake them up. This heal seemed to have effect and they are Online again now. In the meanwhile until I tried this (10 days) the controller kept them flagged as Failed despite they did commuicate very often with the controller (both are PIRs and are triggered a lot)

For the 3rd device the issue is still there. But that device is a sh**ty SF812 smoke detector. This device does not support any kind of wake up (probably acutally not zwave compliant). Therefore I can understand the controller flags it dead.
It only reports in case of fire, test fire alarm and low batt. I triggered a few test alarms. These are received by the controller and processed perfectly. But since there is no wake up and therefore no Heal possible … still flagged failed.

This is merely an update about my observations :wink:


(Herbert) #2352

Dear Chris!

Thx for the feedback. The device is not battery operated - it’s this one: http://www.cd-jackson.com/index.php/zwave/zwave-device-database/zwave-device-list/devicesummary/247
Could you please just check if the db needs to be updated due to a newer FW-Version (I uploaded the xml file with the mentioned error).

Concerning controller reset: do you mean hard or soft reset in habmin (hard reset is hard with many devices…)?
All the points mentioned (not finalised interrogation, cannot add further node) concern the thermostat device (node 57).

Regards,
Herbert


(Leo Siepel) #2353

About group associations: It looks like the association can only be set to the node, not the endpoint. Maybe i need to explain it a bit more.

I have two Fibaro Dimmer 2’s. Each module controls its own light with S1 button. On each device association group 4 (corrosponding to S2 button) is set to the other node. This way i can control both lights from each dimmer.
BUT :slight_smile: when i press S1 on one module, the S2 button of the other module does not get updated.

Module A => press S1 => Light turns on.
Module B => press S2 => nothing happens (it sends On frame to Light A), because it doesn’t know module A was allready turned on.
Module B => press S2 => Light turns off.

Not sure of ZWave protocol / Fibaro dimmers support this, but it would be nice if you could set asociation group 2 (S1) to module S2 endpoint

Another thing: I think i asked about this before in a different thread. But is there a reason why association group 4 (s2) cannot be set to the node itself. I would like to be able to do so. Say this module S1 controls one light in the room and S2 is associated to all of the lights in that room. I have to click both buttons to turn everything on/off. If you would be able to association group 4 with the node itself, you could just press S2 to turn everything in that room off.


(Chris Jackson) #2354

It won’t be a database issue - the binding should download this data from the device without any database information.

I meant a soft reset for now - just unpower the stick will also do the same thing (ie remove it from the USB).

Cheers
Chris


(Chris Jackson) #2355

Well, this shouldn’t be the case so we will need more information on the device, logs, and what you’re trying to do exactly.

Does the device actually support multi-instance associations? According to the database it doesn’t, but maybe that’s incorrect?

There are lots of different ways that different devices trigger multi-instance reports. This is something that has changed a lot over the past year or two with 3 different versions of the MCA command class and probably a lot more implementations as different manufacturers have implemented different things. It really seems a bit of a mess (IMHO!).

No - this should work if the device supports multi-channel association. I’m not sure if it’s a good idea, but that’s a different question.


(Michael Parment) #2356

Have updated to the new binding.

Deleted all things

Uninstalled old binding

Copied new binding to addons

Added back all things

Now i can not get ZW095 gen5 home energy meter to report values.

It seems that i can not set Association Group.
If i set it to OpenHAB Controller


I get another value when going back into configuration

and i have no reporting to controller.

/Mike


(Scott Rushworth) #2357

Do you get the same result if you set the association through Habmin? Be aware that the associations will display as empty or an X on some devices after selecting another device.


(Michael Parment) #2358

I get is as x in habmin and this in Paperui


/Mike


(Scott Rushworth) #2359

I was asking though if you had tried setting the association in Habmin. The UI is a mess, but I haven’t had trouble using it to set the association.


(Michael Parment) #2360

My last response was after i tried to set association in Habmin.

/Mike


(Michael Parment) #2361

Log from when trying to set assosiation

2018-01-12 10:17:56.372 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 13: Configuration update received
2018-01-12 10:17:56.377 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 13: Configuration update config_11_1 to 10
2018-01-12 10:17:56.381 [DEBUG] [class.ZWaveConfigurationCommandClass] - NODE 13: Creating new message for application command CONFIGURATION_SET
2018-01-12 10:17:56.383 [DEBUG] [ommandClassTransactionPayloadBuilder] - At build null
2018-01-12 10:17:56.385 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 13: Encapsulating message, endpoint 0
2018-01-12 10:17:56.387 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 13: SECURITY not supported
2018-01-12 10:17:56.390 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 13: Command Class COMMAND_CLASS_CONFIGURATION is NOT required to be secured
2018-01-12 10:17:56.392 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 13: Adding to device queue
2018-01-12 10:17:56.394 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 13: Added to queue - size 3
2018-01-12 10:17:56.396 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start
2018-01-12 10:17:56.398 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: listening == false, frequentlyListening == false, awake == false
2018-01-12 10:17:56.401 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: Node not awake!
2018-01-12 10:17:56.403 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 7: listening == false, frequentlyListening == false, awake == false
2018-01-12 10:17:56.405 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 7: Node not awake!
2018-01-12 10:17:56.407 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 13: listening == true, frequentlyListening == false, awake == false
2018-01-12 10:17:56.409 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction from sendQueue
2018-01-12 10:17:56.411 [DEBUG] [nal.protocol.ZWaveTransactionManager] - getTransactionToSend 6
2018-01-12 10:17:56.415 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0C 00 13 0D 05 70 04 0B 01 0A 25 9D 24
2018-01-12 10:17:56.419 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 13: Sending REQUEST Message = 01 0C 00 13 0D 05 70 04 0B 01 0A 25 9D 24
2018-01-12 10:17:56.423 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2018-01-12 10:17:56.425 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0x00], type=ACK[0x02], dest=255, callback=0, payload=
2018-01-12 10:17:56.427 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lock Message: class=null[0x00], type=ACK[0x02], dest=255, callback=0, payload=
2018-01-12 10:17:56.429 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0x00], type=ACK[0x02], dest=255, callback=0, payload=
2018-01-12 10:17:56.431 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2018-01-12 10:17:56.431 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2018-01-12 10:17:56.433 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2018-01-12 10:17:56.421 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2018-01-12 10:17:56.435 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2018-01-12 10:17:56.435 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 3340: Transaction Start type SendData
2018-01-12 10:17:56.436 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start
2018-01-12 10:17:56.437 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 3340: [WAIT_RESPONSE] requiresResponse=false callback: 157
2018-01-12 10:17:56.439 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT 6
2018-01-12 10:17:56.439 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd class: null
2018-01-12 10:17:56.441 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd: 0
2018-01-12 10:17:56.442 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[0x13], type=Response[0x01], dest=255, callback=0, payload=01
2018-01-12 10:17:56.444 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage Transactions outstanding: 1
2018-01-12 10:17:56.445 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lock Message: class=SendData[0x13], type=Response[0x01], dest=255, callback=0, payload=01
2018-01-12 10:17:56.447 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Fri Jan 12 10:17:58 CET 2018 - 2000ms
2018-01-12 10:17:56.449 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage lastTransaction: TID 3340: [WAIT_RESPONSE] requiresResponse=false callback: 157
2018-01-12 10:17:56.452 [DEBUG] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
2018-01-12 10:17:56.455 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Fri Jan 12 10:17:58 CET 2018 - 1992ms
2018-01-12 10:17:56.457 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction lastTransaction outstanding...
2018-01-12 10:17:56.457 [DEBUG] [class.ZWaveConfigurationCommandClass] - NODE 13: Creating new message for application command CONFIGURATIONCMD_GET
2018-01-12 10:17:56.459 [DEBUG] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
2018-01-12 10:17:56.460 [DEBUG] [ommandClassTransactionPayloadBuilder] - At build COMMAND_CLASS_CONFIGURATION
2018-01-12 10:17:56.461 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Fri Jan 12 10:17:58 CET 2018 - 1985ms
2018-01-12 10:17:56.456 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 9D 00 00 03 75
2018-01-12 10:17:56.464 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[0x13], type=Response[0x01], dest=255, callback=0, payload=01
2018-01-12 10:17:56.470 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 3340: [WAIT_RESPONSE] requiresResponse=false callback: 157
2018-01-12 10:17:56.472 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2018-01-12 10:17:56.463 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 13: Encapsulating message, endpoint 0
2018-01-12 10:17:56.473 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT 6
2018-01-12 10:17:56.474 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 3340: [WAIT_RESPONSE] requiresResponse=false callback: 157
2018-01-12 10:17:56.474 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 13: SECURITY not supported
2018-01-12 10:17:56.476 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 13: Command Class COMMAND_CLASS_CONFIGURATION is NOT required to be secured
2018-01-12 10:17:56.477 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[0x13], type=Request[0x00], dest=0, callback=157, payload=9D 00 00 03
2018-01-12 10:17:56.479 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[0x13], type=Response[0x01], dest=255, callback=0, payload=01
2018-01-12 10:17:56.478 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 13: Adding to device queue
2018-01-12 10:17:56.481 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lock Message: class=SendData[0x13], type=Request[0x00], dest=0, callback=157, payload=9D 00 00 03
2018-01-12 10:17:56.481 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 13: Added to queue - size 3
2018-01-12 10:17:56.483 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 13: sentData successfully placed on stack.
2018-01-12 10:17:56.486 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 3340: TransactionAdvance ST: WAIT_RESPONSE
2018-01-12 10:17:56.488 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 3340: TransactionAdvance WT: null {}
2018-01-12 10:17:56.489 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start
2018-01-12 10:17:56.490 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 3340: TransactionAdvance RX: Message: class=SendData[0x13], type=Response[0x01], dest=255, callback=0, payload=01
2018-01-12 10:17:56.491 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 3340: TransactionAdvance TO: WAIT_REQUEST
2018-01-12 10:17:56.493 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 3340: Advanced to WAIT_REQUEST
2018-01-12 10:17:56.495 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 13: TID 3340: Transaction not completed
2018-01-12 10:17:56.493 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction lastTransaction outstanding...
2018-01-12 10:17:56.497 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[0x13], type=Request[0x00], dest=0, callback=157, payload=9D 00 00 03
2018-01-12 10:17:56.499 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 3340: [WAIT_REQUEST] requiresResponse=false callback: 157
2018-01-12 10:17:56.499 [DEBUG] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
2018-01-12 10:17:56.507 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Fri Jan 12 10:18:01 CET 2018 - 4989ms
2018-01-12 10:17:56.509 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2018-01-12 10:17:56.511 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 3340: [WAIT_REQUEST] requiresResponse=false callback: 157
2018-01-12 10:17:56.512 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 3340: (Callback 157)
2018-01-12 10:17:56.514 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2018-01-12 10:17:56.514 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 13: Configuration update config_10_1 to 10
2018-01-12 10:17:56.516 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 3340: callback 157
2018-01-12 10:17:56.518 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[0x13], type=Request[0x00], dest=0, callback=157, payload=9D 00 00 03
2018-01-12 10:17:56.518 [DEBUG] [class.ZWaveConfigurationCommandClass] - NODE 13: Creating new message for application command CONFIGURATION_SET
2018-01-12 10:17:56.519 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 13: SendData Request. CallBack ID = 157, Status = Transmission complete and ACK received(0)
2018-01-12 10:17:56.521 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 3340: Transaction COMPLETED
2018-01-12 10:17:56.521 [DEBUG] [ommandClassTransactionPayloadBuilder] - At build null
2018-01-12 10:17:56.523 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 3340: TransactionAdvance ST: DONE
2018-01-12 10:17:56.524 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 3340: TransactionAdvance WT: null {}
2018-01-12 10:17:56.524 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 13: Encapsulating message, endpoint 0
2018-01-12 10:17:56.526 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 3340: TransactionAdvance RX: Message: class=SendData[0x13], type=Request[0x00], dest=0, callback=157, payload=9D 00 00 03
2018-01-12 10:17:56.528 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 3340: TransactionAdvance TO: DONE
2018-01-12 10:17:56.528 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 13: SECURITY not supported
2018-01-12 10:17:56.529 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 13: Response processed after 94ms
2018-01-12 10:17:56.531 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 13: TID 3340: Transaction completed
2018-01-12 10:17:56.532 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 13: notifyTransactionResponse TID:3340 DONE
2018-01-12 10:17:56.531 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 13: Command Class COMMAND_CLASS_CONFIGURATION is NOT required to be secured
2018-01-12 10:17:56.535 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
2018-01-12 10:17:56.536 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 13: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2018-01-12 10:17:56.536 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 13: Adding to device queue
2018-01-12 10:17:56.538 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2018-01-12 10:17:56.539 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start
2018-01-12 10:17:56.540 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 13: Added to queue - size 4
2018-01-12 10:17:56.543 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: listening == false, frequentlyListening == false, awake == false
2018-01-12 10:17:56.543 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start
2018-01-12 10:17:56.545 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: Node not awake!
2018-01-12 10:17:56.546 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 7: listening == false, frequentlyListening == false, awake == false
2018-01-12 10:17:56.548 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 7: Node not awake!
2018-01-12 10:17:56.549 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 13: listening == true, frequentlyListening == false, awake == false
2018-01-12 10:17:56.551 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction from sendQueue
2018-01-12 10:17:56.552 [DEBUG] [nal.protocol.ZWaveTransactionManager] - getTransactionToSend 6
2018-01-12 10:17:56.555 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 0D 03 70 05 0B 25 9E 2D
2018-01-12 10:17:56.557 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 13: Sending REQUEST Message = 01 0A 00 13 0D 03 70 05 0B 25 9E 2D
2018-01-12 10:17:56.559 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2018-01-12 10:17:56.561 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2018-01-12 10:17:56.563 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0x00], type=ACK[0x02], dest=255, callback=0, payload=
2018-01-12 10:17:56.564 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lock Message: class=null[0x00], type=ACK[0x02], dest=255, callback=0, payload=
2018-01-12 10:17:56.565 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 3341: Transaction Start type SendData
2018-01-12 10:17:56.568 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2018-01-12 10:17:56.568 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 3341: [WAIT_RESPONSE] requiresResponse=false callback: 158
2018-01-12 10:17:56.570 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT 6
2018-01-12 10:17:56.570 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd class: COMMAND_CLASS_CONFIGURATION
2018-01-12 10:17:56.572 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd: 6
2018-01-12 10:17:56.572 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 1<>127 : Message: class=SendData[0x13], type=Response[0x01], dest=255, callback=0, payload=01
2018-01-12 10:17:56.574 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lock Message: class=SendData[0x13], type=Response[0x01], dest=255, callback=0, payload=01
2018-01-12 10:17:56.574 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage Transactions outstanding: 1
2018-01-12 10:17:56.576 [DEBUG] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
2018-01-12 10:17:56.578 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Fri Jan 12 10:17:58 CET 2018 - 1998ms
2018-01-12 10:17:56.580 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage lastTransaction: TID 3341: [WAIT_RESPONSE] requiresResponse=false callback: 158
2018-01-12 10:17:56.582 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction lastTransaction outstanding...
2018-01-12 10:17:56.584 [DEBUG] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
2018-01-12 10:17:56.588 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 9E 00 00 03 76
2018-01-12 10:17:56.591 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Fri Jan 12 10:17:58 CET 2018 - 1989ms
2018-01-12 10:17:56.594 [DEBUG] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
2018-01-12 10:17:56.594 [DEBUG] [class.ZWaveConfigurationCommandClass] - NODE 13: Creating new message for application command CONFIGURATIONCMD_GET
2018-01-12 10:17:56.596 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Fri Jan 12 10:17:58 CET 2018 - 1980ms
2018-01-12 10:17:56.596 [DEBUG] [ommandClassTransactionPayloadBuilder] - At build COMMAND_CLASS_CONFIGURATION
2018-01-12 10:17:56.598 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 13: Encapsulating message, endpoint 0
2018-01-12 10:17:56.600 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (1): Message: class=null[0x00], type=ACK[0x02], dest=255, callback=0, payload=
2018-01-12 10:17:56.601 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 13: SECURITY not supported
2018-01-12 10:17:56.602 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 3341: [WAIT_RESPONSE] requiresResponse=false callback: 158
2018-01-12 10:17:56.604 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT 6
2018-01-12 10:17:56.605 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2018-01-12 10:17:56.607 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 1<>127 : Message: class=SendData[0x13], type=Request[0x00], dest=0, callback=158, payload=9E 00 00 03
2018-01-12 10:17:56.609 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lock Message: class=SendData[0x13], type=Request[0x00], dest=0, callback=158, payload=9E 00 00 03
2018-01-12 10:17:56.613 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0E 00 04 00 0D 08 70 06 0B 01 0A 00 00 00 86
2018-01-12 10:17:56.612 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[0x13], type=Response[0x01], dest=255, callback=0, payload=01
2018-01-12 10:17:56.603 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 13: Command Class COMMAND_CLASS_CONFIGURATION is NOT required to be secured
2018-01-12 10:17:56.618 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 13: Adding to device queue
2018-01-12 10:17:56.621 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 13: Added to queue - size 4
2018-01-12 10:17:56.623 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 3341: [WAIT_RESPONSE] requiresResponse=false callback: 158
2018-01-12 10:17:56.623 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start
2018-01-12 10:17:56.625 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT 6
2018-01-12 10:17:56.627 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2018-01-12 10:17:56.628 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 1<>127 : Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=13, callback=0, payload=00 0D 08 70 06 0B 01 0A 00 00 00
2018-01-12 10:17:56.629 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 3341: [WAIT_RESPONSE] requiresResponse=false callback: 158
2018-01-12 10:17:56.630 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lock Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=13, callback=0, payload=00 0D 08 70 06 0B 01 0A 00 00 00
2018-01-12 10:17:56.633 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[0x13], type=Response[0x01], dest=255, callback=0, payload=01
2018-01-12 10:17:56.636 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 13: sentData successfully placed on stack.
2018-01-12 10:17:56.641 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 3341: TransactionAdvance ST: WAIT_RESPONSE
2018-01-12 10:17:56.633 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction lastTransaction outstanding...
2018-01-12 10:17:56.645 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 3341: TransactionAdvance WT: ApplicationCommandHandler {}
2018-01-12 10:17:56.646 [DEBUG] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
2018-01-12 10:17:56.648 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 3341: TransactionAdvance RX: Message: class=SendData[0x13], type=Response[0x01], dest=255, callback=0, payload=01
2018-01-12 10:17:56.648 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Fri Jan 12 10:17:58 CET 2018 - 1928ms
2018-01-12 10:17:56.650 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 3341: TransactionAdvance TO: WAIT_REQUEST
2018-01-12 10:17:56.651 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 13: Configuration update group_1 to [node_1_1]
2018-01-12 10:17:56.653 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 3341: Advanced to WAIT_REQUEST
2018-01-12 10:17:56.653 [DEBUG] [ss.ZWaveMultiAssociationCommandClass] - NODE 13: Creating new message for command MULTI_ASSOCIATIONCMD_REMOVE
2018-01-12 10:17:56.655 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 13: TID 3341: Transaction not completed
2018-01-12 10:17:56.655 [DEBUG] [ommandClassTransactionPayloadBuilder] - At build null
2018-01-12 10:17:56.658 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (1): Message: class=SendData[0x13], type=Request[0x00], dest=0, callback=158, payload=9E 00 00 03
2018-01-12 10:17:56.660 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 3341: [WAIT_REQUEST] requiresResponse=false callback: 158
2018-01-12 10:17:56.662 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2018-01-12 10:17:56.665 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 3341: [WAIT_REQUEST] requiresResponse=false callback: 158
2018-01-12 10:17:56.669 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 3341: (Callback 158)
2018-01-12 10:17:56.671 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2018-01-12 10:17:56.657 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 13: Encapsulating message, endpoint 0
2018-01-12 10:17:56.674 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 3341: callback 158
2018-01-12 10:17:56.675 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 13: SECURITY not supported
2018-01-12 10:17:56.677 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[0x13], type=Request[0x00], dest=0, callback=158, payload=9E 00 00 03
2018-01-12 10:17:56.678 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 13: Command Class COMMAND_CLASS_MULTI_CHANNEL_ASSOCIATION is NOT required to be secured
2018-01-12 10:17:56.680 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 13: SendData Request. CallBack ID = 158, Status = Transmission complete and ACK received(0)
2018-01-12 10:17:56.680 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 13: Adding to device queue
2018-01-12 10:17:56.682 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 3341: TransactionAdvance ST: WAIT_REQUEST
2018-01-12 10:17:56.682 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 13: Added to queue - size 5
2018-01-12 10:17:56.685 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 3341: TransactionAdvance WT: ApplicationCommandHandler {}
2018-01-12 10:17:56.685 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start
2018-01-12 10:17:56.688 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 3341: TransactionAdvance RX: Message: class=SendData[0x13], type=Request[0x00], dest=0, callback=158, payload=9E 00 00 03
2018-01-12 10:17:56.690 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 3341: TransactionAdvance RQ: RREQ=false, RCLS=ApplicationCommandHandler
2018-01-12 10:17:56.692 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 3341: TransactionAdvance TO: DONE
2018-01-12 10:17:56.695 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 3341: Advanced to DONE
2018-01-12 10:17:56.687 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction lastTransaction outstanding...


(Austris V) #2362

Jan2 binding;
uninstalled ZW095, installed back as a new thing.
In the associations, Group1 even showing Controller name in HABMIN.

After initialization is done, can see the values showing up. At some point can see three
2018-01-12 21:48:58.023 [ERROR] [class.ZWaveMultiInstanceCommandClass] - NODE 55: Endpoint 4 not found. Cannot set command classes.
errors in the log file (full log), but have suspicious Chris will say it’s expected :wink:

My other dilemma is (I don’t think it’s related with binding update, just now started looking at it) - I can’t seem to get working the ‘regular’ reporting.
e.g. I switch off selective reporting (param3=0);
Report Group1 for wall watts (param101=1794);
Group1 interval for 10 seconds (param111=10)

but, independant of param111, changes coming in with a 30min interval only :frowning:


(Michael Parment) #2363

What controller do you have?
I have deleted and reinstalled but i always get diffrent endpoints at node1.

/Mike


(Austris V) #2364

Aeotec Z-Stick


(Michael Parment) #2365

Now i have tested the ZW095 in Demoticz and it works well.
When i move back the stick i receive

: CRC check failed message contains EC 06  but should be 02 C2
2018-01-13 14:23:48.812 [INFO ] [.ZWaveCRC16EncapsulationCommandClass] - NODE 14: CRC check failed message contains FD 3C  but should be 21 BB
2018-01-13 14:23:49.107 [INFO ] [.ZWaveCRC16EncapsulationCommandClass] - NODE 14: CRC check failed message contains A5 5F  but should be 79 D8
2018-01-13 14:23:49.410 [INFO ] [.ZWaveCRC16EncapsulationCommandClass] - NODE 14: CRC check failed message contains 47 46  but should be A9 82
2018-01-13 14:23:49.984 [INFO ] [.ZWaveCRC16EncapsulationCommandClass] - NODE 14: CRC check failed message contains B2 B8  but should be 5C 7C
2018-01-13 14:23:50.268 [INFO ] [.ZWaveCRC16EncapsulationCommandClass] - NODE 14: CRC check failed message contains C0 70  but should be 2E B4
2018-01-13 14:23:50.551 [INFO ] [.ZWaveCRC16EncapsulationCommandClass] - NODE 14: CRC check failed message contains 2C 67  but should be C2 A3
2018-01-13 14:23:50.841 [INFO ] [.ZWaveCRC16EncapsulationCommandClass] - NODE 14: CRC check failed message contains A9 EA  but should be 75 6D
2018-01-13 14:23:51.136 [INFO ] [.ZWaveCRC16EncapsulationCommandClass] - NODE 14: CRC check failed message contains 7F A9  but should be A3 2E
2018-01-13 14:23:51.448 [INFO ] [.ZWaveCRC16EncapsulationCommandClass] - NODE 14: CRC check failed message contains 3B 8C  but should be E7 0B
2018-01-13 14:23:52.255 [INFO ] [.ZWaveCRC16EncapsulationCommandClass] - NODE 14: CRC check failed message contains DF 7C  but should be 03 FB

Does someone have any ideas before i move back to the old binding.

/Mike


(Eric Santelices) #2366

I have a 914TRL deadbolt, and a ZStick, I took the ZStick and included the deadbolt. I then attempted to add the deadbolt to OH2.2 which failed. When OH2 initially saw the switch it was labeled properly as a deadbolt, etc… However when I attempted to add it as a thing the addition failed. I searched and found that I needed to switch to the latest zwave snapshot binding which I did successfully, however now whenever I try and add the deadbolt via HABmin or via PaperUI I get the following warning and the device shows up as unknown.

[WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 14: Device discovery could not resolve to a thingType! 7FFFFFFF:7FFFFFFF:7FFFFFFF::0.0
[INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zwave:device:0057a30a:node14' to inbox.

It appears that somewhere there is a “cache” of node14 that’s mapped to the failed inclusion, how can I fix this issue?


(Chris Jackson) #2367

What do you mean by this? Do you mean you removed the stick from the computer running OH, took it to the door to include the device, and then plugged it back in to OH? If so, this won’t work - you MUST include the device from openHAB.


(Eric Santelices) #2368

Yes, that’s what I did. I realize now that won’t work. But now every time I include the device in HABmin the deadbolt is detected but it’s not detecting the device properly and it’s coming in as a generic Zwave device, so HABmin won’t attempt to setup the security.


(Chris Jackson) #2369

Secure inclusion is performed well before any device detection. You need to completely reset the lock first. Then include it, and if secure inclusion is successful, then the device type will be detected - not the other way around.

Secure inclusion must occur within 15 to 20 seconds of the device inclusion - if that doesn’t work, or if the device is already included, then it will fail.


(Eric Santelices) #2370

I found the instructions to exclude the deadbolt from my Zstick and successfully removed it. I tried adding the deadbolt using HABmin, it was discovered on the network however security is now failing, and the deadbolt is listed as an Unknown device

2018-01-13 12:27:40.667 [arthome.event.BindingEvent] - org.openhab.binding.zwave.event.BindingEvent@21f239
2018-01-13 12:27:45.751 [home.event.InboxAddedEvent] - Discovery Result with UID 'zwave:device:0057a30a:node15' has been added.
2018-01-13 12:27:45.749 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zwave:device:0057a30a:node15' to inbox.
2018-01-13 12:27:56.857 [INFO ] [mmandclass.ZWaveSecurityCommandClass] - NODE 15: Using Scheme0 Network Key for Key Exchange since we are in inclusion mode.
2018-01-13 12:28:09.775 [me.event.InboxRemovedEvent] - Discovery Result with UID 'zwave:device:0057a30a:node15' has been removed.
2018-01-13 12:28:09.799 [hingStatusInfoChangedEvent] - 'zwave:device:0057a30a:node15' changed from UNINITIALIZED to INITIALIZING
2018-01-13 12:28:09.804 [hingStatusInfoChangedEvent] - 'zwave:device:0057a30a:node15' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline
2018-01-13 12:28:09.813 [hingStatusInfoChangedEvent] - 'zwave:device:0057a30a:node15' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
2018-01-13 12:28:09.855 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:0057a30a:node15' has been updated.
2018-01-13 12:28:09.907 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:0057a30a:node15' has been updated.
2018-01-13 12:29:13.519 [ERROR] [alization.ZWaveNodeInitStageAdvancer] - NODE 15: SECURITY_INC State=FAILED
2018-01-13 12:29:13.522 [arthome.event.BindingEvent] - org.openhab.binding.zwave.event.BindingEvent@2a93fe