ZWave binding updates

robjkamp · September 27, 2018, 1:12pm

I have waked up one of the devices and that worked. The other one showed that it woke up but the backend did not show any signs of recognition. I removed the node and reinserted.

Now it all works like a charm!

Masssssy · September 29, 2018, 4:14pm

So has anyone managed to get this running on 2.3? 2.4 breaks another binding of mine and my older Z-wave development w/ security binding lacks a new Z-wave device in the DB. I.e can’t really upgrade to 2.4 right now and it would be great if it was possible to get this running on 2.3 so I can install my new device.

chris · September 29, 2018, 4:47pm

Yes - it should work ok under 2.3, but you obviously need to install manually if you’re on the stable branch.

muere · October 4, 2018, 8:23am

Installation: openhabian on Raspberry 3B
Update: openHAB 2.4.0 Build # 1380
Aeotec Gen5 USB stick
Things about PaperUI installed.

Update process as above.
If I remove those things, then delete the zwave binding, cache and temp empty, reboot OH and then reinstall the zwave binding,
things are automatically transferred to the inbox.
Is that correct?
My problem is that all power devices are working properly and all battery devices are not working. e.g .:
With the Fibaro Motion Sensor FMGS001 zw2.7, the motion detector only works with the channel alarm_tamper!

chris · October 4, 2018, 10:04am

You need to wake the battery devices up -:

muere · October 4, 2018, 10:06am

I woke up at least 100 times

chris · October 4, 2018, 11:18am

Then please check the debug logs to be sure that the device is waking up - this is the only thing that should stop battery devices initialising.

muere · October 4, 2018, 11:24am

Where do I see this?

2018-10-04 13:20:56.280 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 13 00 49 84 19 0D 04 A1 02 30 9C 60 85 8E 72 70 86 80 84 D5

2018-10-04 13:20:56.289 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0&lt;&gt;128 : Message: class=ApplicationUpdate[73], type=Request[0], dest=25, callback=132, payload=84 19 0D 04 A1 02 30 9C 60 85 8E 72 70 86 80 84

2018-10-04 13:20:56.294 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationUpdate[73], type=Request[0], dest=25, callback=132, payload=84 19 0D 04 A1 02 30 9C 60 85 8E 72 70 86 80 84

2018-10-04 13:20:56.296 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null

2018-10-04 13:20:56.298 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 0

2018-10-04 13:20:56.300 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: null

2018-10-04 13:20:56.304 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=ApplicationUpdate[73], type=Request[0], dest=25, callback=132, payload=84 19 0D 04 A1 02 30 9C 60 85 8E 72 70 86 80 84

2018-10-04 13:20:56.306 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 25: Application update request. Node information received. Transaction null

2018-10-04 13:20:56.308 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 25: resetResendCount initComplete=true isDead=false

2018-10-04 13:20:56.310 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 25: Application update - no transaction.

2018-10-04 13:20:56.312 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2018-10-04 13:20:56.314 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2018-10-04 13:20:56.563 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 25: Is awake with 0 messages in the queue

2018-10-04 13:20:56.567 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 25: Start sleep timer at 1000ms

2018-10-04 13:20:56.569 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 25: Got an event from Z-Wave network: ZWaveNodeStatusEvent

2018-10-04 13:20:56.602 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 25: Node Status event - Node is AWAKE

==&gt; /var/log/openhab2/events.log &lt;==

2018-10-04 13:20:56.613 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:512:node25' has been updated.

==&gt; /var/log/openhab2/openhab.log &lt;==

2018-10-04 13:20:57.069 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 25: WakeupTimerTask 0 Messages waiting, state DONE

2018-10-04 13:20:57.568 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 25: WakeupTimerTask 0 Messages waiting, state DONE

2018-10-04 13:20:57.570 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 25: No more messages, go back to sleep

2018-10-04 13:20:57.572 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 25: Creating new message for application command WAKE_UP_NO_MORE_INFORMATION

2018-10-04 13:20:57.574 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 25: SECURITY not supported

2018-10-04 13:20:57.576 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 25: Command Class COMMAND_CLASS_WAKE_UP is NOT required to be secured

2018-10-04 13:20:57.578 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 25: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@1c4594d

2018-10-04 13:20:57.581 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 25: Bump transaction 430 priority from Immediate to Immediate

2018-10-04 13:20:57.584 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 25: Adding to device queue

2018-10-04 13:20:57.587 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 25: Added 430 to queue - size 7

2018-10-04 13:20:57.589 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2018-10-04 13:20:57.593 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 19 02 84 08 25 41 16

2018-10-04 13:20:57.596 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 25: Sending REQUEST Message = 01 09 00 13 19 02 84 08 25 41 16

2018-10-04 13:20:57.598 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT

2018-10-04 13:20:57.600 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 430: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 65

2018-10-04 13:20:57.601 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06

2018-10-04 13:20:57.604 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0&lt;&gt;128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=

2018-10-04 13:20:57.606 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=

2018-10-04 13:20:57.613 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 430: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 65

2018-10-04 13:20:57.613 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8

2018-10-04 13:20:57.616 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK

2018-10-04 13:20:57.616 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0&lt;&gt;128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01

2018-10-04 13:20:57.617 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2018-10-04 13:20:57.620 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2018-10-04 13:20:57.622 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01

2018-10-04 13:20:57.625 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 430: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 65

2018-10-04 13:20:57.627 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1

2018-10-04 13:20:57.627 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 41 00 00 03 A9

2018-10-04 13:20:57.629 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 430: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 65

2018-10-04 13:20:57.632 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0&lt;&gt;128 : Message: class=SendData[19], type=Request[0], dest=0, callback=65, payload=41 00 00 03

2018-10-04 13:20:57.635 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01

2018-10-04 13:20:57.637 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 25: sentData successfully placed on stack.

2018-10-04 13:20:57.639 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 430: Advanced to WAIT_REQUEST

2018-10-04 13:20:57.641 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 25: TID 430: Transaction not completed

2018-10-04 13:20:57.644 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=65, payload=41 00 00 03

2018-10-04 13:20:57.646 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 430: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 65

2018-10-04 13:20:57.647 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1

2018-10-04 13:20:57.649 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 430: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 65

2018-10-04 13:20:57.651 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 430: (Callback 65)

2018-10-04 13:20:57.653 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!

2018-10-04 13:20:57.655 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 430: callback 65

2018-10-04 13:20:57.657 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=65, payload=41 00 00 03

2018-10-04 13:20:57.659 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 25: SendData Request. CallBack ID = 65, Status = Transmission complete and ACK received(0)

2018-10-04 13:20:57.661 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 25: resetResendCount initComplete=true isDead=false

2018-10-04 13:20:57.663 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 430: Transaction COMPLETED

2018-10-04 13:20:57.665 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 25: Response processed after 65ms

2018-10-04 13:20:57.667 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 25: TID 430: Transaction completed

2018-10-04 13:20:57.669 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 25: notifyTransactionResponse TID:430 DONE

2018-10-04 13:20:57.671 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 25: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent

2018-10-04 13:20:57.673 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2018-10-04 13:20:57.671 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 430: Transaction event listener: DONE: DONE -&gt;

2018-10-04 13:20:57.675 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2018-10-04 13:20:57.677 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 25: Went to sleep COMPLETE

chris · October 4, 2018, 11:31am

This shows that initialisation is complete. If it’s not really complete, you will need to get a full log from binding startup, or reinitialisation (through the reinitialise menu option) of the device so we can see what is happening.

muere · October 4, 2018, 11:51am

Do you mean the complete openhab.log?
But I can not attach the * .log.

mhilbush · October 4, 2018, 11:55am

You can put it on a file sharing service and include the link in the post. Or, you can open a ticket on Chris’s web site and attach the log to the ticket.
https://www.cd-jackson.com/index.php/tickets

muere · October 4, 2018, 12:12pm

Thanks, could it attach to a ticket.

muere · October 5, 2018, 9:02am

sending:
Log of reinitialization Node 26
Fibaro Flood Sensor today at 10:40

https://www.cd-jackson.com/index.php/tickets
Ticket ID :P3T28d9NqGC

muere · October 5, 2018, 9:34am

Done !
Reinitializing each device solved my problem.

thefathefa · October 6, 2018, 8:40pm

@chris, thanks a lot for the amazing job on the refactoring.

I have a “newbie” type of question : The devices I use (Popp valves) are offering a dedicated command “COMMAND_CLASS_PROTECTION” which allows to lock the local configuration of the valve.
I was wondering if there is a way for me to send this command with the binding and where I should look to understand how to do that.

Thanks again,

chris · October 7, 2018, 9:49pm

I’m glad - I just looked at your log and it looks fine so I’m pleased it’s working .

chris · October 7, 2018, 9:53pm

No - this isn’t currently possible. Please can you raise an issue and I’ll have a look at what is required. This class is fundamentally supported, but needs a bit more code to make it available via a channel.

thefathefa · October 8, 2018, 5:22pm

Ok, I submitted an issue. Thanks a lot for the support!

Chris_si · October 12, 2018, 7:00pm

Since I updated to the latest openHAB version my z-wave nodes don’t work anymore. I already deleted all z-wave things and the controller and added them via PaperUI again.

Here is a little excerpt from the log viewer. The shown devices are Fibaro Wall Plugs.

2018-10-12 20:38:52.465 [hingStatusInfoChangedEvent] - 'zwave:device:762b5c8d:node5' changed from OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller to ONLINE: Node initialising: GET_CONFIGURATION

2018-10-12 20:38:52.473 [hingStatusInfoChangedEvent] - 'zwave:device:762b5c8d:node5' changed from ONLINE: Node initialising: GET_CONFIGURATION to ONLINE: Node initialising: DYNAMIC_VALUES

2018-10-12 20:39:56.529 [WARN ] [mon.registry.AbstractManagedProvider] - Could not update element with key _tags:c_f_wp_01 in ManagedMetadataProviderImpl, because it does not exists.

2018-10-12 20:41:13.185 [hingStatusInfoChangedEvent] - 'zwave:device:762b5c8d:node2' changed from ONLINE: Node initialising: PING to ONLINE

2018-10-12 20:41:28.049 [hingStatusInfoChangedEvent] - 'zwave:device:762b5c8d:node2' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller

Neither of them is working.
Is there something else I need to do to get them working again?

chris · October 12, 2018, 7:32pm

The device seems to have occasionally communicated, but if the binding is showing it offline, then it means that there are some responses missing.

Maybe they are too far away from the controller? Or maybe there’s another issue - it’s really hard to say without the debug log though - what you’ve provided is the events log.