Qubino flush shutter goes offline with communication error

Hi,

I have a qubino flush shutter which I tried to use on latest openhab 2.3.0 stable. The inclusion was flawless and all endpoints were created. It even worked first showing as online and I could remote control blinds up and down. It even reported back when blinds were manually opened and closed and at first I was happy.

But then all of a sudden the device was offline not reacting anymore and the logs showed this:

2018-08-21 20:26:21.029 [hingStatusInfoChangedEvent] - 'zwave:device:81ab7676:node4' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller

2018-08-21 20:36:15.069 [hingStatusInfoChangedEvent] - 'zwave:device:81ab7676:node4' changed from OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller to ONLINE

2018-08-21 20:36:20.309 [hingStatusInfoChangedEvent] - 'zwave:device:81ab7676:node4' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller

2018-08-21 20:36:20.321 [hingStatusInfoChangedEvent] - 'zwave:device:81ab7676:node4' changed from OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller to ONLINE

2018-08-21 20:36:20.709 [hingStatusInfoChangedEvent] - 'zwave:device:81ab7676:node4' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller

2018-08-21 20:46:19.053 [hingStatusInfoChangedEvent] - 'zwave:device:81ab7676:node4' changed from OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller to ONLINE

2018-08-21 20:46:24.023 [hingStatusInfoChangedEvent] - 'zwave:device:81ab7676:node4' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller

2018-08-21 20:56:27.490 [hingStatusInfoChangedEvent] - 'zwave:device:81ab7676:node4' changed from OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller to ONLINE

2018-08-21 20:56:35.471 [hingStatusInfoChangedEvent] - 'zwave:device:81ab7676:node4' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller

2018-08-21 20:56:35.918 [hingStatusInfoChangedEvent] - 'zwave:device:81ab7676:node4' changed from OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller to ONLINE

2018-08-21 20:56:47.917 [hingStatusInfoChangedEvent] - 'zwave:device:81ab7676:node4' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller

2018-08-21 21:16:14.845 [hingStatusInfoChangedEvent] - 'zwave:device:81ab7676:node4' changed from OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller to ONLINE

2018-08-21 21:16:16.151 [hingStatusInfoChangedEvent] - 'zwave:device:81ab7676:node4' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller

2018-08-21 21:16:16.241 [hingStatusInfoChangedEvent] - 'zwave:device:81ab7676:node4' changed from OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller to ONLINE

2018-08-21 21:26:35.457 [hingStatusInfoChangedEvent] - 'zwave:device:81ab7676:node4' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller

2018-08-21 21:26:35.574 [hingStatusInfoChangedEvent] - 'zwave:device:81ab7676:node4' changed from OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller to ONLINE

2018-08-21 21:26:43.713 [hingStatusInfoChangedEvent] - 'zwave:device:81ab7676:node4' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller

2018-08-21 21:36:18.959 [hingStatusInfoChangedEvent] - 'zwave:device:81ab7676:node4' changed from OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller to ONLINE

2018-08-21 21:36:20.114 [hingStatusInfoChangedEvent] - 'zwave:device:81ab7676:node4' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller

2018-08-21 21:46:14.976 [hingStatusInfoChangedEvent] - 'zwave:device:81ab7676:node4' changed from OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller to ONLINE

2018-08-21 21:46:16.308 [hingStatusInfoChangedEvent] - 'zwave:device:81ab7676:node4' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller

2018-08-21 21:46:16.412 [hingStatusInfoChangedEvent] - 'zwave:device:81ab7676:node4' changed from OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller to ONLINE

2018-08-21 21:46:31.621 [hingStatusInfoChangedEvent] - 'zwave:device:81ab7676:node4' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller

2018-08-21 21:56:23.140 [hingStatusInfoChangedEvent] - 'zwave:device:81ab7676:node4' changed from OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller to ONLINE

2018-08-21 21:56:36.302 [hingStatusInfoChangedEvent] - 'zwave:device:81ab7676:node4' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller

2018-08-21 21:56:44.747 [hingStatusInfoChangedEvent] - 'zwave:device:81ab7676:node4' changed from OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller to ONLINE

2018-08-21 21:56:56.976 [hingStatusInfoChangedEvent] - 'zwave:device:81ab7676:node4' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller

2018-08-21 22:00:01.997 [ome.event.ItemCommandEvent] - Item 'Airc_Actions' received command LOW

For some reason at some point the messages just stop, sometimes they start reappearing after some time.

I then tried various stuff reinitialisation, heal, etc. in then I tried exclusion which was failing too as exclusion command was not sent to the device.

So, I thought maybe just bad luck, let’s reset the whole thing. So I deleted the Thing, removed the xml file restarted openhab and resetted the qubino completely (press I1 5 times after power-on in first 60 seconds).

Then I finally could do a proper fresh inclusion and it came back showing online, working perfectly. But again after about 16 hours the same messages started to appear.

What’s the problem with this thing, like this it’s useless. Is there any config value I have to set or do I have to increase/decrease polling time or what’s the reason for this behaviour?

Thanks for any help cause it’s driving me crazy.

I can confirm that I have the exact same errors with a Qubino ZMNHBD Flush 2 relay. After working perfect for a while, then the Node not communicating errors start appearing in the log and in Habmin (things) . I’m on OH2.4 with z-wave binding 2.4.0.201811281515, currently the most recent z-wave binding. I don’t know what is causing this, but it’s quite annoying.

Perhaps the z-wave antenna is being interfered with by the metal housing. I’ve just got another ZMNHBD Flush 2 relay. I´ll see how that one works. But actually it looks more like some sort of bug.

I’ve checked the debug log (see below), it seems that after receiving an update from the node, the node is set offline NODE 12: Setting OFFLINE after that node12' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller and then the node stays dead (red cross in Habmin).

Some time later, when the node sends an update (message) it goes online and then again COMMUNICATION_ERROR.

Anyone, a clue?

==> /var/log/openhab2/openhab.log <==
2018-11-30 02:08:05.798 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Polling...
2018-11-30 02:08:05.803 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Polling zwave:device:c949557e:node12:switch_binary
2018-11-30 02:08:05.804 [DEBUG] [converter.ZWaveBinarySwitchConverter] - NODE 12: Generating poll message for COMMAND_CLASS_SWITCH_BINARY, endpoint 0
2018-11-30 02:08:05.805 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 12: Creating new message for application command SWITCH_BINARY_GET
2018-11-30 02:08:05.808 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: SECURITY not supported
2018-11-30 02:08:05.809 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: Command Class COMMAND_CLASS_SWITCH_BINARY is NOT required to be secured
2018-11-30 02:08:05.810 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Polling skipped for zwave:device:c949557e:node12:switch_binary on COMMAND_CLASS_BASIC
2018-11-30 02:08:05.811 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Polling zwave:device:c949557e:node12:meter_watts
2018-11-30 02:08:05.812 [DEBUG] [ternal.converter.ZWaveMeterConverter] - NODE 12: Generating poll message for COMMAND_CLASS_METER, endpoint 0
2018-11-30 02:08:05.812 [DEBUG] [ternal.converter.ZWaveMeterConverter] - NODE 12: Generating poll message for COMMAND_CLASS_METER, endpoint 0
2018-11-30 02:08:05.813 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 12: Creating new message for application command METER_GET
2018-11-30 02:08:05.814 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: SECURITY not supported
2018-11-30 02:08:05.814 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: Command Class COMMAND_CLASS_METER is NOT required to be secured
2018-11-30 02:08:05.815 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Polling zwave:device:c949557e:node12:meter_kwh
2018-11-30 02:08:05.815 [DEBUG] [ternal.converter.ZWaveMeterConverter] - NODE 12: Generating poll message for COMMAND_CLASS_METER, endpoint 0
2018-11-30 02:08:05.816 [DEBUG] [ternal.converter.ZWaveMeterConverter] - NODE 12: Generating poll message for COMMAND_CLASS_METER, endpoint 0
2018-11-30 02:08:05.816 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 12: Creating new message for application command METER_GET
2018-11-30 02:08:05.816 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: SECURITY not supported
2018-11-30 02:08:05.817 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: Command Class COMMAND_CLASS_METER is NOT required to be secured
2018-11-30 02:08:05.817 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Polling zwave:device:c949557e:node12:switch_binary1
2018-11-30 02:08:05.817 [DEBUG] [converter.ZWaveBinarySwitchConverter] - NODE 12: Generating poll message for COMMAND_CLASS_SWITCH_BINARY, endpoint 1
2018-11-30 02:08:05.818 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 12: Creating new message for application command SWITCH_BINARY_GET
2018-11-30 02:08:05.818 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: Encapsulating message, instance / endpoint 1
2018-11-30 02:08:05.819 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 12: Creating new message for command MULTI_CHANNEL_ENCAP endpoint 1
2018-11-30 02:08:05.819 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: SECURITY not supported
2018-11-30 02:08:05.820 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: Command Class COMMAND_CLASS_MULTI_CHANNEL is NOT required to be secured
2018-11-30 02:08:05.820 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Polling skipped for zwave:device:c949557e:node12:switch_binary1 on COMMAND_CLASS_BASIC
2018-11-30 02:08:05.821 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Polling zwave:device:c949557e:node12:meter_watts1
2018-11-30 02:08:05.821 [DEBUG] [ternal.converter.ZWaveMeterConverter] - NODE 12: Generating poll message for COMMAND_CLASS_METER, endpoint 1
2018-11-30 02:08:05.822 [DEBUG] [ternal.converter.ZWaveMeterConverter] - NODE 12: Generating poll message for COMMAND_CLASS_METER, endpoint 1
2018-11-30 02:08:05.822 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 12: Creating new message for application command METER_GET
2018-11-30 02:08:05.822 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: Encapsulating message, instance / endpoint 1
2018-11-30 02:08:05.823 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 12: Creating new message for command MULTI_CHANNEL_ENCAP endpoint 1
2018-11-30 02:08:05.823 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: SECURITY not supported
2018-11-30 02:08:05.823 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: Command Class COMMAND_CLASS_MULTI_CHANNEL is NOT required to be secured
2018-11-30 02:08:05.824 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Polling zwave:device:c949557e:node12:meter_kwh1
2018-11-30 02:08:05.825 [DEBUG] [ternal.converter.ZWaveMeterConverter] - NODE 12: Generating poll message for COMMAND_CLASS_METER, endpoint 1
2018-11-30 02:08:05.825 [DEBUG] [ternal.converter.ZWaveMeterConverter] - NODE 12: Generating poll message for COMMAND_CLASS_METER, endpoint 1
2018-11-30 02:08:05.826 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 12: Creating new message for application command METER_GET
2018-11-30 02:08:05.826 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: Encapsulating message, instance / endpoint 1
2018-11-30 02:08:05.827 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 12: Creating new message for command MULTI_CHANNEL_ENCAP endpoint 1
2018-11-30 02:08:05.827 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: SECURITY not supported
2018-11-30 02:08:05.827 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: Command Class COMMAND_CLASS_MULTI_CHANNEL is NOT required to be secured
2018-11-30 02:08:05.828 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Polling zwave:device:c949557e:node12:switch_binary2
2018-11-30 02:08:05.828 [DEBUG] [converter.ZWaveBinarySwitchConverter] - NODE 12: Generating poll message for COMMAND_CLASS_SWITCH_BINARY, endpoint 2
2018-11-30 02:08:05.828 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 12: Creating new message for application command SWITCH_BINARY_GET
2018-11-30 02:08:05.829 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: Encapsulating message, instance / endpoint 2
2018-11-30 02:08:05.829 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 12: Creating new message for command MULTI_CHANNEL_ENCAP endpoint 2
2018-11-30 02:08:05.829 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: SECURITY not supported
2018-11-30 02:08:05.830 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: Command Class COMMAND_CLASS_MULTI_CHANNEL is NOT required to be secured
2018-11-30 02:08:05.830 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Polling skipped for zwave:device:c949557e:node12:switch_binary2 on COMMAND_CLASS_BASIC
2018-11-30 02:08:05.830 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Polling zwave:device:c949557e:node12:meter_watts2
2018-11-30 02:08:05.831 [DEBUG] [ternal.converter.ZWaveMeterConverter] - NODE 12: Generating poll message for COMMAND_CLASS_METER, endpoint 2
2018-11-30 02:08:05.831 [DEBUG] [ternal.converter.ZWaveMeterConverter] - NODE 12: Generating poll message for COMMAND_CLASS_METER, endpoint 2
2018-11-30 02:08:05.831 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 12: Creating new message for application command METER_GET
2018-11-30 02:08:05.832 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: Encapsulating message, instance / endpoint 2
2018-11-30 02:08:05.832 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 12: Creating new message for command MULTI_CHANNEL_ENCAP endpoint 2
2018-11-30 02:08:05.832 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: SECURITY not supported
2018-11-30 02:08:05.833 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: Command Class COMMAND_CLASS_MULTI_CHANNEL is NOT required to be secured
2018-11-30 02:08:05.833 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Polling zwave:device:c949557e:node12:meter_kwh2
2018-11-30 02:08:05.834 [DEBUG] [ternal.converter.ZWaveMeterConverter] - NODE 12: Generating poll message for COMMAND_CLASS_METER, endpoint 2
2018-11-30 02:08:05.834 [DEBUG] [ternal.converter.ZWaveMeterConverter] - NODE 12: Generating poll message for COMMAND_CLASS_METER, endpoint 2
2018-11-30 02:08:05.834 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 12: Creating new message for application command METER_GET
2018-11-30 02:08:05.834 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: Encapsulating message, instance / endpoint 2
2018-11-30 02:08:05.835 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 12: Creating new message for command MULTI_CHANNEL_ENCAP endpoint 2
2018-11-30 02:08:05.835 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: SECURITY not supported
2018-11-30 02:08:05.835 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: Command Class COMMAND_CLASS_MULTI_CHANNEL is NOT required to be secured
2018-11-30 02:08:05.837 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Adding to device queue
2018-11-30 02:08:05.838 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Added 132 to queue - size 6
2018-11-30 02:08:05.839 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2018-11-30 02:08:05.840 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 0C 02 25 02 25 A5 4C 
2018-11-30 02:08:05.841 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 12: Sending REQUEST Message = 01 09 00 13 0C 02 25 02 25 A5 4C 
2018-11-30 02:08:05.842 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2018-11-30 02:08:05.843 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 132: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 165
2018-11-30 02:08:05.845 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Adding to device queue
2018-11-30 02:08:05.845 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Added 133 to queue - size 6
2018-11-30 02:08:05.846 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2018-11-30 02:08:05.847 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2018-11-30 02:08:05.848 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2018-11-30 02:08:05.849 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2018-11-30 02:08:05.851 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 132: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 165
2018-11-30 02:08:05.853 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK

==> /var/log/openhab2/events.log <==
2018-11-30 02:08:05.853 [vent.ItemStateChangedEvent] - zwave_serial_zstick_c949557e_serial_ack changed from 302 to 303

==> /var/log/openhab2/openhab.log <==
2018-11-30 02:08:05.855 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
2018-11-30 02:08:05.857 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

==> /var/log/openhab2/events.log <==
2018-11-30 02:08:05.858 [vent.ItemStateChangedEvent] - zwave_serial_zstick_c949557e_serial_sof changed from 563 to 564

==> /var/log/openhab2/openhab.log <==
2018-11-30 02:08:05.849 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Adding to device queue
2018-11-30 02:08:05.859 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2018-11-30 02:08:05.860 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Added 134 to queue - size 7
2018-11-30 02:08:05.860 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2018-11-30 02:08:05.861 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2018-11-30 02:08:05.861 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 132: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 165
2018-11-30 02:08:05.861 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2018-11-30 02:08:05.862 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 132: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 165
2018-11-30 02:08:05.862 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2018-11-30 02:08:05.862 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2018-11-30 02:08:05.863 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Adding to device queue
2018-11-30 02:08:05.864 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Added 135 to queue - size 8
2018-11-30 02:08:05.864 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2018-11-30 02:08:05.865 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 12: sentData successfully placed on stack.
2018-11-30 02:08:05.866 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 132: Advanced to WAIT_REQUEST
2018-11-30 02:08:05.866 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: TID 132: Transaction not completed
2018-11-30 02:08:05.866 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2018-11-30 02:08:05.865 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Adding to device queue
2018-11-30 02:08:05.867 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Added 136 to queue - size 9
2018-11-30 02:08:05.867 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2018-11-30 02:08:05.867 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2018-11-30 02:08:05.868 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Adding to device queue
2018-11-30 02:08:05.868 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Added 137 to queue - size 10
2018-11-30 02:08:05.868 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2018-11-30 02:08:05.869 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Adding to device queue
2018-11-30 02:08:05.869 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Added 138 to queue - size 11
2018-11-30 02:08:05.869 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2018-11-30 02:08:05.870 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Adding to device queue
2018-11-30 02:08:05.870 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Added 139 to queue - size 12
2018-11-30 02:08:05.870 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2018-11-30 02:08:05.871 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Adding to device queue
2018-11-30 02:08:05.871 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Added 140 to queue - size 13
2018-11-30 02:08:05.871 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2018-11-30 02:08:08.215 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 0C 03 25 03 FF 24 

==> /var/log/openhab2/events.log <==
2018-11-30 02:08:08.219 [vent.ItemStateChangedEvent] - zwave_serial_zstick_c949557e_serial_sof changed from 564 to 565

==> /var/log/openhab2/openhab.log <==
2018-11-30 02:08:08.221 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=12, callback=0, payload=00 0C 03 25 03 FF 
2018-11-30 02:08:08.232 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=12, callback=0, payload=00 0C 03 25 03 FF 
2018-11-30 02:08:08.232 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 132: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 165
2018-11-30 02:08:08.233 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Application Command Request (ALIVE:DONE)
2018-11-30 02:08:08.233 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: resetResendCount initComplete=true isDead=false
2018-11-30 02:08:08.237 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: Incoming command class COMMAND_CLASS_SWITCH_BINARY, endpoint 0
2018-11-30 02:08:08.237 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: SECURITY not supported
2018-11-30 02:08:08.240 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 12: Received COMMAND_CLASS_SWITCH_BINARY V1 SWITCH_BINARY_REPORT
2018-11-30 02:08:08.243 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 12: Switch Binary report, value = 255
2018-11-30 02:08:08.252 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2018-11-30 02:08:08.257 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Got a value event from Z-Wave network, endpoint = 0, command class = COMMAND_CLASS_SWITCH_BINARY, value = 255
2018-11-30 02:08:08.263 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Updating channel state zwave:device:c949557e:node12:switch_binary to ON [OnOffType]
2018-11-30 02:08:08.269 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Commands processed 1.
2018-11-30 02:08:08.275 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@7eef160e.
2018-11-30 02:08:08.276 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2018-11-30 02:08:08.278 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2018-11-30 02:08:08.280 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2018-11-30 02:08:08.284 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2018-11-30 02:08:12.132 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 A5 01 02 04 49 
2018-11-30 02:08:12.099 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 12: TID 132: Timeout at state WAIT_REQUEST. 3 retries remaining.

....
==> /var/log/openhab2/openhab.log <==
2018-11-30 02:08:14.051 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 0C 03 25 03 FF 24 
2018-11-30 02:08:14.054 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=12, callback=0, payload=00 0C 03 25 03 FF 
2018-11-30 02:08:14.056 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=12, callback=0, payload=00 0C 03 25 03 FF 
2018-11-30 02:08:14.057 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 132: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 166
2018-11-30 02:08:14.058 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Application Command Request (ALIVE:DONE)
2018-11-30 02:08:14.059 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: resetResendCount initComplete=true isDead=false
2018-11-30 02:08:14.061 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: Incoming command class COMMAND_CLASS_SWITCH_BINARY, endpoint 0
2018-11-30 02:08:14.062 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: SECURITY not supported
2018-11-30 02:08:14.063 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 12: Received COMMAND_CLASS_SWITCH_BINARY V1 SWITCH_BINARY_REPORT
2018-11-30 02:08:14.064 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 12: Switch Binary report, value = 255
2018-11-30 02:08:14.065 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2018-11-30 02:08:14.066 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Got a value event from Z-Wave network, endpoint = 0, command class = COMMAND_CLASS_SWITCH_BINARY, value = 255
2018-11-30 02:08:14.067 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Updating channel state zwave:device:c949557e:node12:switch_binary to ON [OnOffType]
2018-11-30 02:08:14.069 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Commands processed 1.
2018-11-30 02:08:14.071 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@2af98fe.
2018-11-30 02:08:14.072 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2018-11-30 02:08:14.073 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2018-11-30 02:08:14.073 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2018-11-30 02:08:14.074 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2018-11-30 02:08:15.032 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 0C 03 25 03 FF 24 

==> /var/log/openhab2/events.log <==
2018-11-30 02:08:15.041 [vent.ItemStateChangedEvent] - zwave_serial_zstick_c949557e_serial_sof changed from 568 to 569

==> /var/log/openhab2/openhab.log <==
2018-11-30 02:08:15.053 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=12, callback=0, payload=00 0C 03 25 03 FF 
2018-11-30 02:08:15.057 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=12, callback=0, payload=00 0C 03 25 03 FF 
2018-11-30 02:08:15.058 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 132: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 166
2018-11-30 02:08:15.058 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Application Command Request (ALIVE:DONE)
2018-11-30 02:08:15.059 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: resetResendCount initComplete=true isDead=false
2018-11-30 02:08:15.060 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: Incoming command class COMMAND_CLASS_SWITCH_BINARY, endpoint 0
2018-11-30 02:08:15.061 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: SECURITY not supported
2018-11-30 02:08:15.062 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 12: Received COMMAND_CLASS_SWITCH_BINARY V1 SWITCH_BINARY_REPORT
2018-11-30 02:08:15.064 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 12: Switch Binary report, value = 255
2018-11-30 02:08:15.069 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2018-11-30 02:08:15.099 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Got a value event from Z-Wave network, endpoint = 0, command class = COMMAND_CLASS_SWITCH_BINARY, value = 255
2018-11-30 02:08:15.117 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Updating channel state zwave:device:c949557e:node12:switch_binary to ON [OnOffType]
2018-11-30 02:08:15.140 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Commands processed 1.
2018-11-30 02:08:15.146 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@57deabc9.
2018-11-30 02:08:15.151 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2018-11-30 02:08:15.157 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2018-11-30 02:08:15.162 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2018-11-30 02:08:15.170 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2018-11-30 02:08:17.548 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 12: TID 132: Timeout at state WAIT_REQUEST. 2 retries remaining.
2018-11-30 02:08:17.550 [DEBUG] [sactionManager$ZWaveTransactionTimer] - Aborting Transaction!
2018-11-30 02:08:17.551 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 132: Transaction ABORTED
2018-11-30 02:08:17.552 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 16 EA 
2018-11-30 02:08:17.553 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 16 EA 
2018-11-30 02:08:17.555 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2018-11-30 02:08:17.557 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2018-11-30 02:08:17.560 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2018-11-30 02:08:17.560 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2018-11-30 02:08:17.563 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2018-11-30 02:08:17.564 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 132: [ABORTED] priority=Get, requiresResponse=true, callback: 166

==> /var/log/openhab2/events.log <==
2018-11-30 02:08:17.563 [vent.ItemStateChangedEvent] - zwave_serial_zstick_c949557e_serial_ack changed from 305 to 306

==> /var/log/openhab2/openhab.log <==
2018-11-30 02:08:17.565 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2018-11-30 02:08:17.566 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2018-11-30 02:08:17.567 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2018-11-30 02:08:17.614 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 A6 01 02 01 4F 

==> /var/log/openhab2/events.log <==
2018-11-30 02:08:17.616 [vent.ItemStateChangedEvent] - zwave_serial_zstick_c949557e_serial_sof changed from 569 to 570

==> /var/log/openhab2/openhab.log <==
2018-11-30 02:08:17.619 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=1, callback=166, payload=A6 01 02 01 
2018-11-30 02:08:17.620 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=1, callback=166, payload=A6 01 02 01 
2018-11-30 02:08:17.621 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 132: [ABORTED] priority=Get, requiresResponse=true, callback: 166
2018-11-30 02:08:17.621 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2018-11-30 02:08:17.622 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 132: [ABORTED] priority=Get, requiresResponse=true, callback: 166
2018-11-30 02:08:17.622 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 132: (Callback 166)
2018-11-30 02:08:17.622 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2018-11-30 02:08:17.623 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 132: callback 166
2018-11-30 02:08:17.623 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=166, payload=A6 01 02 01 
2018-11-30 02:08:17.628 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 12: SendData Request. CallBack ID = 166, Status = Transmission complete, no ACK received(1)
2018-11-30 02:08:17.630 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 132: Transaction CANCELLED
2018-11-30 02:08:17.631 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2018-11-30 02:08:17.632 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: CANCEL while sending message. Requeueing - 1 attempts left!
2018-11-30 02:08:17.633 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 132: Transaction RESET with 1 retries remaining.
2018-11-30 02:08:17.634 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Adding to device queue
2018-11-30 02:08:17.635 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Added 132 to queue - size 14
2018-11-30 02:08:17.636 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2018-11-30 02:08:17.637 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 0C 02 25 02 25 A7 4E 
2018-11-30 02:08:17.638 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 12: Sending REQUEST Message = 01 09 00 13 0C 02 25 02 25 A7 4E 
2018-11-30 02:08:17.639 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2018-11-30 02:08:17.639 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 132: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 167
2018-11-30 02:08:17.641 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06

==> /var/log/openhab2/events.log <==
2018-11-30 02:08:17.643 [vent.ItemStateChangedEvent] - zwave_serial_zstick_c949557e_serial_ack changed from 306 to 307

==> /var/log/openhab2/openhab.log <==
2018-11-30 02:08:17.645 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2018-11-30 02:08:17.651 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 

==> /var/log/openhab2/events.log <==
2018-11-30 02:08:17.650 [vent.ItemStateChangedEvent] - zwave_serial_zstick_c949557e_serial_sof changed from 570 to 571

==> /var/log/openhab2/openhab.log <==
2018-11-30 02:08:17.648 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: TID 132: Transaction not completed
2018-11-30 02:08:17.653 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 1<>127 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2018-11-30 02:08:17.654 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (1): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2018-11-30 02:08:17.656 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 132: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 167
2018-11-30 02:08:17.657 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2018-11-30 02:08:17.658 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2018-11-30 02:08:17.659 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 132: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 167
2018-11-30 02:08:17.660 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2018-11-30 02:08:17.661 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 132: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 167
2018-11-30 02:08:17.664 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2018-11-30 02:08:17.665 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 12: sentData successfully placed on stack.
2018-11-30 02:08:17.665 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 132: Advanced to WAIT_REQUEST
2018-11-30 02:08:17.666 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: TID 132: Transaction not completed
2018-11-30 02:08:17.667 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2018-11-30 02:08:17.668 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2018-11-30 02:08:17.827 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 0C 03 25 03 FF 24 

==> /var/log/openhab2/events.log <==
2018-11-30 02:08:17.944 [vent.ItemStateChangedEvent] - zwave_serial_zstick_c949557e_serial_sof changed from 571 to 572

==> /var/log/openhab2/openhab.log <==
2018-11-30 02:08:17.946 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=12, callback=0, payload=00 0C 03 25 03 FF 
2018-11-30 02:08:17.947 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=12, callback=0, payload=00 0C 03 25 03 FF 
2018-11-30 02:08:17.947 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 132: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 167
2018-11-30 02:08:17.948 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Application Command Request (ALIVE:DONE)
2018-11-30 02:08:17.948 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: resetResendCount initComplete=true isDead=false
2018-11-30 02:08:17.948 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: Incoming command class COMMAND_CLASS_SWITCH_BINARY, endpoint 0
2018-11-30 02:08:17.949 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: SECURITY not supported
2018-11-30 02:08:17.949 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 12: Received COMMAND_CLASS_SWITCH_BINARY V1 SWITCH_BINARY_REPORT
2018-11-30 02:08:17.950 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 12: Switch Binary report, value = 255
2018-11-30 02:08:17.950 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2018-11-30 02:08:17.951 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Got a value event from Z-Wave network, endpoint = 0, command class = COMMAND_CLASS_SWITCH_BINARY, value = 255
2018-11-30 02:08:17.951 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Updating channel state zwave:device:c949557e:node12:switch_binary to ON [OnOffType]
2018-11-30 02:08:17.956 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Commands processed 1.
2018-11-30 02:08:17.957 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@754a28ca.
2018-11-30 02:08:17.957 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2018-11-30 02:08:17.958 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2018-11-30 02:08:17.958 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2018-11-30 02:08:17.958 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2018-11-30 02:08:19.793 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 0C 03 25 03 FF 24 

==> /var/log/openhab2/events.log <==
2018-11-30 02:08:19.796 [vent.ItemStateChangedEvent] - zwave_serial_zstick_c949557e_serial_sof changed from 572 to 573

==> /var/log/openhab2/openhab.log <==
2018-11-30 02:08:19.798 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=12, callback=0, payload=00 0C 03 25 03 FF 
2018-11-30 02:08:19.799 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=12, callback=0, payload=00 0C 03 25 03 FF 
2018-11-30 02:08:19.799 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 132: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 167
2018-11-30 02:08:19.800 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Application Command Request (ALIVE:DONE)
2018-11-30 02:08:19.800 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: resetResendCount initComplete=true isDead=false
2018-11-30 02:08:19.801 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: Incoming command class COMMAND_CLASS_SWITCH_BINARY, endpoint 0
2018-11-30 02:08:19.801 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: SECURITY not supported
2018-11-30 02:08:19.802 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 12: Received COMMAND_CLASS_SWITCH_BINARY V1 SWITCH_BINARY_REPORT
2018-11-30 02:08:19.802 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 12: Switch Binary report, value = 255
2018-11-30 02:08:19.803 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2018-11-30 02:08:19.803 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Got a value event from Z-Wave network, endpoint = 0, command class = COMMAND_CLASS_SWITCH_BINARY, value = 255
2018-11-30 02:08:19.804 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Updating channel state zwave:device:c949557e:node12:switch_binary to ON [OnOffType]
2018-11-30 02:08:19.806 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Commands processed 1.
2018-11-30 02:08:19.806 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@73130f0b.
2018-11-30 02:08:19.807 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2018-11-30 02:08:19.807 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2018-11-30 02:08:19.807 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2018-11-30 02:08:19.807 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

==> /var/log/openhab2/openhab.log <==
2018-11-30 02:08:22.666 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 12: TID 132: Timeout at state WAIT_REQUEST. 1 retries remaining.
2018-11-30 02:08:22.667 [DEBUG] [sactionManager$ZWaveTransactionTimer] - Aborting Transaction!
2018-11-30 02:08:22.669 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 132: Transaction ABORTED
2018-11-30 02:08:22.671 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 16 EA 
2018-11-30 02:08:22.672 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 16 EA 
2018-11-30 02:08:22.676 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2018-11-30 02:08:22.677 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2018-11-30 02:08:22.680 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2018-11-30 02:08:22.680 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 132: [ABORTED] priority=Get, requiresResponse=true, callback: 167
2018-11-30 02:08:22.681 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK

==> /var/log/openhab2/events.log <==
2018-11-30 02:08:22.679 [vent.ItemStateChangedEvent] - zwave_serial_zstick_c949557e_serial_ack changed from 307 to 308

==> /var/log/openhab2/openhab.log <==
2018-11-30 02:08:22.682 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2018-11-30 02:08:22.682 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2018-11-30 02:08:22.684 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2018-11-30 02:08:22.685 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2018-11-30 02:08:23.037 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 A7 01 02 1B 54 

==> /var/log/openhab2/events.log <==
2018-11-30 02:08:23.039 [vent.ItemStateChangedEvent] - zwave_serial_zstick_c949557e_serial_sof changed from 573 to 574

==> /var/log/openhab2/openhab.log <==
2018-11-30 02:08:23.043 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=1, callback=167, payload=A7 01 02 1B 
2018-11-30 02:08:23.044 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=1, callback=167, payload=A7 01 02 1B 
2018-11-30 02:08:23.044 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 132: [ABORTED] priority=Get, requiresResponse=true, callback: 167
2018-11-30 02:08:23.045 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2018-11-30 02:08:23.046 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 132: [ABORTED] priority=Get, requiresResponse=true, callback: 167
2018-11-30 02:08:23.046 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 132: (Callback 167)
2018-11-30 02:08:23.047 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2018-11-30 02:08:23.048 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 132: callback 167
2018-11-30 02:08:23.049 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=167, payload=A7 01 02 1B 
2018-11-30 02:08:23.049 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 12: SendData Request. CallBack ID = 167, Status = Transmission complete, no ACK received(1)
2018-11-30 02:08:23.050 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 132: Transaction CANCELLED
2018-11-30 02:08:23.051 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2018-11-30 02:08:23.051 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Retry count exceeded. Discarding message: TID 132: [CANCELLED] priority=Get, requiresResponse=true, callback: 167
2018-11-30 02:08:23.052 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Got an event from Z-Wave network: ZWaveNodeStatusEvent
2018-11-30 02:08:23.054 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Setting OFFLINE
2018-11-30 02:08:23.096 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 12: Node Status event - Node is DEAD

==> /var/log/openhab2/events.log <==
2018-11-30 02:08:23.099 [hingStatusInfoChangedEvent] - 'zwave:device:c949557e:node12' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller

==> /var/log/openhab2/openhab.log <==
2018-11-30 02:08:23.099 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: Node is DEAD.
2018-11-30 02:08:23.101 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Got an event from Z-Wave network: ZWaveNodeStatusEvent
2018-11-30 02:08:23.106 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Setting OFFLINE
2018-11-30 02:08:23.107 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 12: Node Status event - Node is DEAD
2018-11-30 02:08:23.108 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: TID 132: Transaction completed
2018-11-30 02:08:23.108 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: notifyTransactionResponse TID:132 CANCELLED
2018-11-30 02:08:23.111 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2018-11-30 02:08:23.111 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2018-11-30 02:08:23.112 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2018-11-30 02:08:23.112 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 0C 03 32 01 10 25 A8 47 
2018-11-30 02:08:23.113 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 12: Sending REQUEST Message = 01 0A 00 13 0C 03 32 01 10 25 A8 47 
2018-11-30 02:08:23.114 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT

[SOLVED]
I have installed the second Qubino ZMNHBD Flush 2 and the dead node problems seem to have resolved as soon as the second node came online.
So the first node (ZMNHBD) is approximately 7m away from the controller, in between there are some other (powered nodes) like a Fibaro powerplug for instance, that reduces the distance to, about 4 to 5 meters between the controller and a route-able (powered) zwave node

The second ZMNHBD is placed in between controller and the other (powered nodes), which reduces the distance to about 2 to 3 meters between controller and the (new) nearest ZMNHBD node.
I’m using an AEON LABS Gen5 USB stick attached to a PC.

It also looks like the ZMNHBD (or perhaps in general Qubino) have short distance zwave reachability (at least in my experience compared with some other brands). So the problem (COMMUNICATION_ERROR): Node is not communicating with controller is most likely due to a mesh network which is not completely reachable throughout the nodes and controller, because of distance.

Solved!

I can confirm this. At first my zwave stick was attached to a Raspberry sitting on the floor in a cupboard having no problems with other zwave devices just the qubinos. Then I added a USB extension cable and put the zwave stick on the side wall of the cupboard in a height of ~2m above floor which removes some obstacles in direct line of sight from controller to the qubinos and is roughly at the same height as the qubinos. In addition the distance also shortened a bit as direct line of sight is now a bit shorter as when sitting on the floor.

Making this changes made the qubinos work perfectly now since months.