Zwave queue congested by Polling?

Add-ons Bindings
1

I am noticing from time to time that the response time of my ZWAVE-Network with OH2 is slow (e.g. switching a light via UI takes up to 15-20 seconds), while in other moments the response is immediate.
The analyse of my debug logs shows that the OH2 Zwave-binding tries to poll several data from my nodes from time to time which regulary increaes the Queue (often up to a queue length of 25-40).
Here the log:

2017-01-08 18:30:10.752 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 21: Polling...
2017-01-08 18:30:10.752 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 21: Polling zwave:device:15970bead83:node21:switch_binary
2017-01-08 18:30:10.752 [DEBUG] [converter.ZWaveBinarySwitchConverter] - NODE 21: Generating poll message for SWITCH_BINARY, endpoint 0
2017-01-08 18:30:10.752 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 21: Creating new message for application command SWITCH_BINARY_GET
2017-01-08 18:30:10.752 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 21: Polling zwave:device:15970bead83:node21:switch_dimmer
2017-01-08 18:30:10.752 [DEBUG] [erter.ZWaveMultiLevelSwitchConverter] - NODE 21: Generating poll message for SWITCH_MULTILEVEL, endpoint 0
2017-01-08 18:30:10.752 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 21: Creating new message for command SWITCH_MULTILEVEL_GET
2017-01-08 18:30:10.752 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 21: Polling zwave:device:15970bead83:node21:switch_dimmer
2017-01-08 18:30:10.752 [DEBUG] [erter.ZWaveMultiLevelSwitchConverter] - NODE 21: Generating poll message for SWITCH_MULTILEVEL, endpoint 0
2017-01-08 18:30:10.752 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 21: Creating new message for command SWITCH_MULTILEVEL_GET
2017-01-08 18:30:10.752 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 21: Polling zwave:device:15970bead83:node21:sensor_binary
2017-01-08 18:30:10.752 [DEBUG] [converter.ZWaveBinarySensorConverter] - NODE 21: Generating poll message for SENSOR_BINARY, endpoint 0
2017-01-08 18:30:10.752 [DEBUG] [dclass.ZWaveBinarySensorCommandClass] - NODE 21: Creating new message for application command SENSOR_BINARY_GET
2017-01-08 18:30:10.752 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 21: Polling zwave:device:15970bead83:node21:sensor_temperature
2017-01-08 18:30:10.752 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 21: Polling zwave:device:15970bead83:node21:meter_kwh
2017-01-08 18:30:10.752 [DEBUG] [ternal.converter.ZWaveMeterConverter] - NODE 21: Generating poll message for METER, endpoint 0
2017-01-08 18:30:10.752 [DEBUG] [ternal.converter.ZWaveMeterConverter] - NODE 21: Generating poll message for METER, endpoint 0
2017-01-08 18:30:10.752 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 21: Creating new message for application command METER_GET
2017-01-08 18:30:10.752 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 21: Polling zwave:device:15970bead83:node21:meter_watts
2017-01-08 18:30:10.752 [DEBUG] [ternal.converter.ZWaveMeterConverter] - NODE 21: Generating poll message for METER, endpoint 0
2017-01-08 18:30:10.752 [DEBUG] [ternal.converter.ZWaveMeterConverter] - NODE 21: Generating poll message for METER, endpoint 0
2017-01-08 18:30:10.752 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 21: Creating new message for application command METER_GET
2017-01-08 18:30:10.752 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 21: Polling zwave:device:15970bead83:node21:alarm_general
2017-01-08 18:30:10.752 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 21: Polling zwave:device:15970bead83:node21:switch_binary1
2017-01-08 18:30:10.752 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 21: Polling zwave:device:15970bead83:node21:switch_dimmer1
2017-01-08 18:30:10.752 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 21: Polling zwave:device:15970bead83:node21:switch_dimmer1
2017-01-08 18:30:10.752 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 21: Polling zwave:device:15970bead83:node21:meter_kwh1
2017-01-08 18:30:10.752 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 21: Polling zwave:device:15970bead83:node21:meter_watts1
2017-01-08 18:30:10.752 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 21: Polling zwave:device:15970bead83:node21:sensor_binary2
2017-01-08 18:30:10.752 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 21: Polling zwave:device:15970bead83:node21:alarm_general2
2017-01-08 18:30:10.752 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 21: Polling zwave:device:15970bead83:node21:sensor_binary3
2017-01-08 18:30:10.752 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 21: Polling zwave:device:15970bead83:node21:alarm_general3
2017-01-08 18:30:10.752 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 3. Queue={}
2017-01-08 18:30:10.752 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 4. Queue={}
2017-01-08 18:30:10.752 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 5. Queue={}
2017-01-08 18:30:10.752 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 6. Queue={}
2017-01-08 18:30:10.752 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 7. Queue={}
2017-01-08 18:30:10.752 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 8. Queue={}
2017-01-08 18:30:10.832 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0E 00 04 00 61 08 32 02 21 74 00 00 03 5C A6 
2017-01-08 18:30:10.832 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2017-01-08 18:30:10.832 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0E 00 04 00 61 08 32 02 21 74 00 00 03 5C A6 
2017-01-08 18:30:10.833 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 0E 00 04 00 61 08 32 02 21 74 00 00 03 5C A6 
2017-01-08 18:30:10.833 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 61 08 32 02 21 74 00 00 03 5C 
2017-01-08 18:30:10.833 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 97: Application Command Request (ALIVE:DONE)
2017-01-08 18:30:10.833 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 97: Starting initialisation from DONE
2017-01-08 18:30:10.833 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@2c439735 already registered
2017-01-08 18:30:10.833 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 97: Incoming command class METER
2017-01-08 18:30:10.833 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 97: Received METER command V3
2017-01-08 18:30:10.833 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 97: Meter: Type=Electric(1), Scale=W(2), Value=0.86
2017-01-08 18:30:10.833 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveMeterValueEvent
2017-01-08 18:30:10.833 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 97: Got an event from Z-Wave network: ZWaveMeterValueEvent
2017-01-08 18:30:10.833 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 97: Got a value event from Z-Wave network, endpoint = 0, command class = METER, value = 0.86
2017-01-08 18:30:10.833 [DEBUG] [ternal.converter.ZWaveMeterConverter] - Not the right scale E_KWh <> E_W
2017-01-08 18:30:10.833 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 97: Updating channel state zwave:device:15970bead83:node97:meter_watts to 0.86 [DecimalType]
2017-01-08 18:30:10.833 [DEBUG] [ternal.converter.ZWaveMeterConverter] - Not the right scale E_A <> E_W
2017-01-08 18:30:10.833 [DEBUG] [ternal.converter.ZWaveMeterConverter] - Not the right scale E_V <> E_W
2017-01-08 18:30:10.833 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 102: Transaction not completed: node address inconsistent.  lastSent=102, incoming=255
2017-01-08 18:30:10.926 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0E 00 04 00 61 08 32 02 21 74 00 00 03 5C A6 
2017-01-08 18:30:10.927 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2017-01-08 18:30:10.927 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0E 00 04 00 61 08 32 02 21 74 00 00 03 5C A6 
2017-01-08 18:30:10.927 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 0E 00 04 00 61 08 32 02 21 74 00 00 03 5C A6 
2017-01-08 18:30:10.927 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 61 08 32 02 21 74 00 00 03 5C 
2017-01-08 18:30:10.927 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 97: Application Command Request (ALIVE:DONE)
2017-01-08 18:30:10.927 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 97: Starting initialisation from DONE
2017-01-08 18:30:10.927 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@2c439735 already registered
2017-01-08 18:30:10.927 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 97: Incoming command class METER
2017-01-08 18:30:10.927 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 97: Received METER command V3
2017-01-08 18:30:10.927 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 97: Meter: Type=Electric(1), Scale=W(2), Value=0.86
2017-01-08 18:30:10.927 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveMeterValueEvent
2017-01-08 18:30:10.927 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 97: Got an event from Z-Wave network: ZWaveMeterValueEvent
2017-01-08 18:30:10.927 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 97: Got a value event from Z-Wave network, endpoint = 0, command class = METER, value = 0.86
2017-01-08 18:30:10.927 [DEBUG] [ternal.converter.ZWaveMeterConverter] - Not the right scale E_KWh <> E_W
2017-01-08 18:30:10.927 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 97: Updating channel state zwave:device:15970bead83:node97:meter_watts to 0.86 [DecimalType]
2017-01-08 18:30:10.927 [DEBUG] [ternal.converter.ZWaveMeterConverter] - Not the right scale E_A <> E_W
2017-01-08 18:30:10.927 [DEBUG] [ternal.converter.ZWaveMeterConverter] - Not the right scale E_V <> E_W
2017-01-08 18:30:10.927 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 102: Transaction not completed: node address inconsistent.  lastSent=102, incoming=255
2017-01-08 18:30:11.097 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0E 00 04 00 61 08 32 02 21 74 00 00 03 5C A6 
2017-01-08 18:30:11.097 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2017-01-08 18:30:11.097 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0E 00 04 00 61 08 32 02 21 74 00 00 03 5C A6 
2017-01-08 18:30:11.098 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 0E 00 04 00 61 08 32 02 21 74 00 00 03 5C A6 
2017-01-08 18:30:11.098 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 61 08 32 02 21 74 00 00 03 5C 
2017-01-08 18:30:11.098 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 97: Application Command Request (ALIVE:DONE)
2017-01-08 18:30:11.098 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 97: Starting initialisation from DONE
2017-01-08 18:30:11.098 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@2c439735 already registered
2017-01-08 18:30:11.098 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 97: Incoming command class METER
2017-01-08 18:30:11.098 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 97: Received METER command V3
2017-01-08 18:30:11.098 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 97: Meter: Type=Electric(1), Scale=W(2), Value=0.86
2017-01-08 18:30:11.098 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveMeterValueEvent
2017-01-08 18:30:11.098 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 97: Got an event from Z-Wave network: ZWaveMeterValueEvent
2017-01-08 18:30:11.098 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 97: Got a value event from Z-Wave network, endpoint = 0, command class = METER, value = 0.86
2017-01-08 18:30:11.098 [DEBUG] [ternal.converter.ZWaveMeterConverter] - Not the right scale E_KWh <> E_W
2017-01-08 18:30:11.098 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 97: Updating channel state zwave:device:15970bead83:node97:meter_watts to 0.86 [DecimalType]
2017-01-08 18:30:11.098 [DEBUG] [ternal.converter.ZWaveMeterConverter] - Not the right scale E_A <> E_W
2017-01-08 18:30:11.098 [DEBUG] [ternal.converter.ZWaveMeterConverter] - Not the right scale E_V <> E_W
2017-01-08 18:30:11.098 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 102: Transaction not completed: node address inconsistent.  lastSent=102, incoming=255
2017-01-08 18:30:11.616 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 83: Polling...
2017-01-08 18:30:11.616 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 83: Polling zwave:device:15970bead83:node83:switch_binary
2017-01-08 18:30:11.616 [DEBUG] [converter.ZWaveBinarySwitchConverter] - NODE 83: Generating poll message for SWITCH_BINARY, endpoint 0
2017-01-08 18:30:11.616 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 83: Creating new message for application command SWITCH_BINARY_GET
2017-01-08 18:30:11.616 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 83: Polling zwave:device:15970bead83:node83:meter_kwh
2017-01-08 18:30:11.616 [DEBUG] [ternal.converter.ZWaveMeterConverter] - NODE 83: Generating poll message for METER, endpoint 0
2017-01-08 18:30:11.616 [DEBUG] [ternal.converter.ZWaveMeterConverter] - NODE 83: Generating poll message for METER, endpoint 0
2017-01-08 18:30:11.616 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 83: Creating new message for application command METER_GET
2017-01-08 18:30:11.616 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 83: Polling zwave:device:15970bead83:node83:meter_current
2017-01-08 18:30:11.616 [DEBUG] [ternal.converter.ZWaveMeterConverter] - NODE 83: Generating poll message for METER, endpoint 0
2017-01-08 18:30:11.616 [DEBUG] [ternal.converter.ZWaveMeterConverter] - NODE 83: Generating poll message for METER, endpoint 0
2017-01-08 18:30:11.616 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 83: Creating new message for application command METER_GET
2017-01-08 18:30:11.616 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 83: Polling zwave:device:15970bead83:node83:meter_voltage
2017-01-08 18:30:11.616 [DEBUG] [ternal.converter.ZWaveMeterConverter] - NODE 83: Generating poll message for METER, endpoint 0
2017-01-08 18:30:11.616 [DEBUG] [ternal.converter.ZWaveMeterConverter] - NODE 83: Generating poll message for METER, endpoint 0
2017-01-08 18:30:11.616 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 83: Creating new message for application command METER_GET
2017-01-08 18:30:11.616 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 83: Polling zwave:device:15970bead83:node83:meter_watts
2017-01-08 18:30:11.616 [DEBUG] [ternal.converter.ZWaveMeterConverter] - NODE 83: Generating poll message for METER, endpoint 0
2017-01-08 18:30:11.616 [DEBUG] [ternal.converter.ZWaveMeterConverter] - NODE 83: Generating poll message for METER, endpoint 0
2017-01-08 18:30:11.616 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 83: Creating new message for application command METER_GET
2017-01-08 18:30:11.616 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 9. Queue={}
2017-01-08 18:30:11.616 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 10. Queue={}
2017-01-08 18:30:11.616 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 11. Queue={}
2017-01-08 18:30:11.616 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 12. Queue={}
2017-01-08 18:30:11.616 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 13. Queue={}
2017-01-08 18:30:11.683 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 03 03 26 03 00 D7 
2017-01-08 18:30:11.684 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2017-01-08 18:30:11.684 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 04 00 03 03 26 03 00 D7 
2017-01-08 18:30:11.684 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 04 00 03 03 26 03 00 D7 
2017-01-08 18:30:11.684 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 03 03 26 03 00 
2017-01-08 18:30:11.684 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 3: Application Command Request (ALIVE:DONE)
2017-01-08 18:30:11.684 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Starting initialisation from DONE
2017-01-08 18:30:11.684 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@6315556 already registered
2017-01-08 18:30:11.684 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 3: Incoming command class SWITCH_MULTILEVEL
2017-01-08 18:30:11.684 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 3: Received SWITCH_MULTILEVEL command V3
2017-01-08 18:30:11.684 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 3: Switch Multi Level report, value = 0
2017-01-08 18:30:11.684 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveCommandClassValueEvent
2017-01-08 18:30:11.684 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2017-01-08 18:30:11.684 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Got a value event from Z-Wave network, endpoint = 0, command class = SWITCH_MULTILEVEL, value = 0
2017-01-08 18:30:11.684 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Updating channel state zwave:device:15970bead83:node3:switch_dimmer to 0 [PercentType]
2017-01-08 18:30:11.684 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 102: Transaction not completed: node address inconsistent.  lastSent=102, incoming=255
2017-01-08 18:30:12.103 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 E2 01 01 A6 AF 
2017-01-08 18:30:12.104 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2017-01-08 18:30:12.104 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 E2 01 01 A6 00 00 A1 
2017-01-08 18:30:12.104 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 E2 01 01 A6 00 00 A1 
2017-01-08 18:30:12.104 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=E2 01 01 A6 
2017-01-08 18:30:12.104 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 102: SendData Request. CallBack ID = 226, Status = Transmission complete, no ACK received(1)
2017-01-08 18:30:12.104 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 102: Node is DEAD. Dropping message.
2017-01-08 18:30:12.104 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
2017-01-08 18:30:12.104 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 102: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2017-01-08 18:30:12.104 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 102: Response processed after 4230ms/5000ms.
2017-01-08 18:30:12.104 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 12
2017-01-08 18:30:12.104 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0E 00 13 66 07 60 0D 01 02 32 01 00 25 E3 18 
2017-01-08 18:30:12.104 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 102: Sending REQUEST Message = 01 0E 00 13 66 07 60 0D 01 02 32 01 00 25 E3 18 
2017-01-08 18:30:12.118 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
2017-01-08 18:30:12.119 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2017-01-08 18:30:12.119 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8 
2017-01-08 18:30:12.119 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8 
2017-01-08 18:30:12.119 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01 
2017-01-08 18:30:12.119 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 102: Sent Data successfully placed on stack.
2017-01-08 18:30:12.599 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 02 03 26 03 00 D6 
2017-01-08 18:30:12.600 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2017-01-08 18:30:12.600 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 04 00 02 03 26 03 00 D6 
2017-01-08 18:30:12.600 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 04 00 02 03 26 03 00 D6 
2017-01-08 18:30:12.600 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 02 03 26 03 00 
2017-01-08 18:30:12.600 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 2: Application Command Request (ALIVE:DONE)
2017-01-08 18:30:12.600 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Starting initialisation from DONE
2017-01-08 18:30:12.600 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@56d4e295 already registered
2017-01-08 18:30:12.600 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 2: Incoming command class SWITCH_MULTILEVEL
2017-01-08 18:30:12.600 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 2: Received SWITCH_MULTILEVEL command V3
2017-01-08 18:30:12.600 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 2: Switch Multi Level report, value = 0
2017-01-08 18:30:12.600 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveCommandClassValueEvent
2017-01-08 18:30:12.600 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2017-01-08 18:30:12.600 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got a value event from Z-Wave network, endpoint = 0, command class = SWITCH_MULTILEVEL, value = 0
2017-01-08 18:30:12.600 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Updating channel state zwave:device:15970bead83:node2:switch_dimmer to 0 [PercentType]
2017-01-08 18:30:12.600 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 102: Transaction not completed: node address inconsistent.  lastSent=102, incoming=255
2017-01-08 18:30:12.963 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 10 00 04 00 03 0A 32 02 21 34 00 00 00 00 00 00 C7 
2017-01-08 18:30:12.964 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2017-01-08 18:30:12.964 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 10 00 04 00 03 0A 32 02 21 34 00 00 00 00 00 00 C7 
2017-01-08 18:30:12.964 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 10 00 04 00 03 0A 32 02 21 34 00 00 00 00 00 00 C7 
2017-01-08 18:30:12.964 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 03 0A 32 02 21 34 00 00 00 00 00 00 
2017-01-08 18:30:12.964 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 3: Application Command Request (ALIVE:DONE)
2017-01-08 18:30:13.610 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Polling...
2017-01-08 18:30:13.610 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Polling zwave:device:15970bead83:node10:switch_binary
2017-01-08 18:30:13.610 [DEBUG] [converter.ZWaveBinarySwitchConverter] - NODE 10: Generating poll message for SWITCH_BINARY, endpoint 0
2017-01-08 18:30:13.610 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 10: Creating new message for application command SWITCH_BINARY_GET
2017-01-08 18:30:13.610 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Polling zwave:device:15970bead83:node10:switch_dimmer
2017-01-08 18:30:13.610 [DEBUG] [erter.ZWaveMultiLevelSwitchConverter] - NODE 10: Generating poll message for SWITCH_MULTILEVEL, endpoint 0
2017-01-08 18:30:13.610 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 10: Creating new message for command SWITCH_MULTILEVEL_GET
2017-01-08 18:30:13.610 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Polling zwave:device:15970bead83:node10:switch_dimmer
2017-01-08 18:30:13.610 [DEBUG] [erter.ZWaveMultiLevelSwitchConverter] - NODE 10: Generating poll message for SWITCH_MULTILEVEL, endpoint 0
2017-01-08 18:30:13.610 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 10: Creating new message for command SWITCH_MULTILEVEL_GET
2017-01-08 18:30:13.610 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Polling zwave:device:15970bead83:node10:sensor_binary
2017-01-08 18:30:13.610 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Polling zwave:device:15970bead83:node10:sensor_temperature
2017-01-08 18:30:13.610 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Polling zwave:device:15970bead83:node10:meter_kwh
2017-01-08 18:30:13.610 [DEBUG] [ternal.converter.ZWaveMeterConverter] - NODE 10: Generating poll message for METER, endpoint 0
2017-01-08 18:30:13.610 [DEBUG] [ternal.converter.ZWaveMeterConverter] - NODE 10: Generating poll message for METER, endpoint 0
2017-01-08 18:30:13.610 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 10: Creating new message for application command METER_GET
2017-01-08 18:30:13.610 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Polling zwave:device:15970bead83:node10:meter_watts
2017-01-08 18:30:13.610 [DEBUG] [ternal.converter.ZWaveMeterConverter] - NODE 10: Generating poll message for METER, endpoint 0
2017-01-08 18:30:13.610 [DEBUG] [ternal.converter.ZWaveMeterConverter] - NODE 10: Generating poll message for METER, endpoint 0
2017-01-08 18:30:13.610 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 10: Creating new message for application command METER_GET
2017-01-08 18:30:13.610 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Polling zwave:device:15970bead83:node10:alarm_general
2017-01-08 18:30:13.610 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Polling zwave:device:15970bead83:node10:switch_binary1
2017-01-08 18:30:13.610 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Polling zwave:device:15970bead83:node10:switch_dimmer1
2017-01-08 18:30:13.610 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Polling zwave:device:15970bead83:node10:switch_dimmer1
2017-01-08 18:30:13.610 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Polling zwave:device:15970bead83:node10:meter_kwh1
2017-01-08 18:30:13.610 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Polling zwave:device:15970bead83:node10:meter_watts1
2017-01-08 18:30:13.610 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Polling zwave:device:15970bead83:node10:sensor_binary2
2017-01-08 18:30:13.610 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Polling zwave:device:15970bead83:node10:alarm_general2
2017-01-08 18:30:13.610 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Polling zwave:device:15970bead83:node10:sensor_binary3
2017-01-08 18:30:13.610 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Polling zwave:device:15970bead83:node10:alarm_general3
2017-01-08 18:30:13.610 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 13. Queue={}
2017-01-08 18:30:13.610 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 14. Queue={}
2017-01-08 18:30:13.610 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 15. Queue={}
2017-01-08 18:30:13.610 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 16. Queue={}
2017-01-08 18:30:13.610 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 17. Queue={}

I assume that the polling is done because of the default setting proposed by Habmin2:

grafik.png1048×142 3.41 KB

I wonder if this was also the case in OH1 or is this a new system behaviour? Perhaps increasing the time interval here would already help a little bit?

However, I noticed in the log that the Binding is polling several datapoints for each device, even datapoints which are not used, acitivated and not bound to a channel/item. For nodes 10 and 21 for example (see log above), the polling is done for all these datapoints:
NODE 21: Polling zwave:device:15970bead83:node21:switch_binary
NODE 21: Polling zwave:device:15970bead83:node21:switch_dimmer
NODE 21: Polling zwave:device:15970bead83:node21:sensor_binary
NODE 21: Polling zwave:device:15970bead83:node21:sensor_temperature
NODE 21: Polling zwave:device:15970bead83:node21:meter_kwh
NODE 21: Polling zwave:device:15970bead83:node21:meter_watts
NODE 21: Polling zwave:device:15970bead83:node21:alarm_general
NODE 21: Polling zwave:device:15970bead83:node21:switch_binary1
NODE 21: Polling zwave:device:15970bead83:node21:switch_dimmer1
NODE 21: Polling zwave:device:15970bead83:node21:meter_kwh1
NODE 21: Polling zwave:device:15970bead83:node21:meter_watts1
NODE 21: Polling zwave:device:15970bead83:node21:sensor_binary2
NODE 21: Polling zwave:device:15970bead83:node21:alarm_general2
NODE 21: Polling zwave:device:15970bead83:node21:sensor_binary3
NODE 21: Polling zwave:device:15970bead83:node21:alarm_general3

I am only using these nodes as dimmers for light (the devices are Qubino Flush Dimmers ZMNHDD) and use the 2 meters for Watts and kWh enenrgy reporting. These are also the only defined channel-items in my configuration. SO there would be no need to query these values by the binding.
Additionally, the binary sensor functions for endpoints 2 and 3 are disabled in the configuration of the device:

So why is there a polling for this? I have the impression that the binding tries to poll everything that the device in theory could deliver, even if not activated.

So my questions are:

  1. Is this behaviour intended or is this excessive polling a bug?
  2. Is there a way to configure the range of polling (restricting to only used channels)?
  3. If I change the minimum polling period to 1 day (instead of 30 minutes), what is the risk?

Thanks for any help.

2

Yes - the binding polls everything. If it’s only every 30 minutes, I don’t really see the problem though.

The reason this was done is when I first wrote the binding, there was no way for the binding to know that there were items linked to channels - it only knew about channels. Some limited information is now available so I will likely change this, but at the moment it’s not high on the list as there shouldn’t be any problem.

You should remember that the queue is prioritised - polling is the lowest priority - commands are quite high on the list, so if you send a command, it will be queued with a much higher priority than polling - it won’t wait until all polling is completed before sending commands…