[SOLVED] Home Energy Meter HEM G3 AEON Labs GEN5 ZW095 do not report automatically

autoit · August 24, 2019, 7:03pm

Sorry, I must have confused the reporting groups with association groups. Here’s another log with association group 1.

Seeing “node_1_1” in there reminded me: when looking around with the Z-Wave PC Controller, I saw that before adding Node 1, there was already Node 1.1 associated. Not sure if that’s of any significance.

Removing "Controller" from association group 1:

21:04:56.577 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 8: Configuration update received
21:04:56.599 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 8: Configuration update set group_1 to [] (EmptyList)
21:04:56.609 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 8: Association 1 consolidated to []
21:04:56.618 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 8: Current members before update ZWaveAssociationGroup [index=1, name=null, profile1=null, profile2=null, associations=[node_1, node_1_1]]
21:04:56.626 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 8: Members after config update ZWaveAssociationGroup [index=1, name=null, profile1=null, profile2=null, associations=[]]
21:04:56.640 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 8: Controller is master - forcing associations
21:04:56.669 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 8: Group is controller - forcing association
21:04:56.678 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 8: Members after controller update ZWaveAssociationGroup [index=1, name=null, profile1=null, profile2=null, associations=[node_1_1]]
21:04:56.690 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 8: Removing node_1 from association group 1
21:04:56.699 [DEBUG] [ass.ZWaveMultiAssociationCommandClass] - NODE 8: Creating new message for command MULTI_ASSOCIATIONCMD_REMOVE
21:04:56.712 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 8: SECURITY not supported
21:04:56.720 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 8: Command Class COMMAND_CLASS_MULTI_CHANNEL_ASSOCIATION is NOT required to be secured
21:04:56.729 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 8: Adding to device queue
21:04:56.737 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 8: Added 700 to queue - size 4
21:04:56.745 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
21:04:56.758 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0D 00 13 08 06 8E 04 01 00 01 00 25 47 07 
21:04:56.769 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 8: Sending REQUEST Message = 01 0D 00 13 08 06 8E 04 01 00 01 00 25 47 07 
21:04:56.779 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT
21:04:56.782 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
21:04:56.793 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 700: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 71
21:04:56.802 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
21:04:56.806 [DEBUG] [ass.ZWaveMultiAssociationCommandClass] - NODE 8: Creating new message for command MULTI_ASSOCIATIONCMD_GET group 1
21:04:56.815 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
21:04:56.811 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
21:04:56.825 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 8: SECURITY not supported
21:04:56.837 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 700: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 71
21:04:56.843 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 8: Command Class COMMAND_CLASS_MULTI_CHANNEL_ASSOCIATION is NOT required to be secured
21:04:56.854 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
21:04:56.860 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK
21:04:56.863 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 8: Adding to device queue
21:04:56.873 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
21:04:56.872 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 47 00 00 02 AE 
21:04:56.877 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 8: Added 701 to queue - size 4
21:04:56.887 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 700: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 71
21:04:56.900 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
21:04:56.904 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=71, payload=47 00 00 02 
21:04:56.916 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
21:04:56.926 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 700: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 71
21:04:56.934 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
21:04:56.945 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 8: sentData successfully placed on stack.
21:04:56.954 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 700: Advanced to WAIT_REQUEST
21:04:56.964 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 8: TID 700: Transaction not completed
21:04:56.974 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=71, payload=47 00 00 02 
21:04:56.983 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 700: [WAIT_REQUEST] priority=Config, requiresResponse=true, callback: 71
21:04:56.992 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
21:04:57.000 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 700: [WAIT_REQUEST] priority=Config, requiresResponse=true, callback: 71
21:04:57.008 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking TID 700: (Callback 71)
21:04:57.017 [DEBUG] [l.serialmessage.ZWaveCommandProcessor] - Callback match!
21:04:57.028 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Correlated to TID 700: callback 71
21:04:57.036 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=71, payload=47 00 00 02 
21:04:57.047 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 8: SendData Request. CallBack ID = 71, Status = Transmission complete and ACK received(0)
21:04:57.065 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 8: resetResendCount initComplete=true isDead=false
21:04:57.072 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 700: Transaction COMPLETED
21:04:57.083 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 8: Response processed after 290ms
21:04:57.091 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 8: TID 700: Transaction completed
21:04:57.100 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 8: notifyTransactionResponse TID:700 DONE
21:04:57.119 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 8: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
21:04:57.126 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
21:04:57.135 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
21:04:57.146 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 08 03 8E 02 01 25 48 0D 
21:04:57.159 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 8: Sending REQUEST Message = 01 0A 00 13 08 03 8E 02 01 25 48 0D 
21:04:57.165 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT
21:04:57.169 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
21:04:57.175 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 701: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 72
21:04:57.181 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
21:04:57.199 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
21:04:57.200 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
21:04:57.206 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 701: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 72
21:04:57.220 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
21:04:57.220 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK
21:04:57.237 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 48 00 00 02 A1 
21:04:57.237 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
21:04:57.252 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=72, payload=48 00 00 02 
21:04:57.254 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 701: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 72
21:04:57.268 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
21:04:57.269 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0F 00 04 00 08 09 8E 03 01 05 00 01 00 01 01 7D 
21:04:57.277 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 701: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 72
21:04:57.289 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 1<>127 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=0, payload=00 08 09 8E 03 01 05 00 01 00 01 01 
21:04:57.291 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
21:04:57.303 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 8: sentData successfully placed on stack.
21:04:57.312 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 701: Advanced to WAIT_REQUEST
21:04:57.322 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 8: TID 701: Transaction not completed
21:04:57.330 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (1): Message: class=SendData[19], type=Request[0], dest=0, callback=72, payload=48 00 00 02 
21:04:57.338 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 701: [WAIT_REQUEST] priority=Config, requiresResponse=true, callback: 72
21:04:57.346 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
21:04:57.354 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 701: [WAIT_REQUEST] priority=Config, requiresResponse=true, callback: 72
21:04:57.360 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking TID 701: (Callback 72)
21:04:57.369 [DEBUG] [l.serialmessage.ZWaveCommandProcessor] - Callback match!
21:04:57.376 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Correlated to TID 701: callback 72
21:04:57.384 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=72, payload=48 00 00 02 
21:04:57.394 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 8: SendData Request. CallBack ID = 72, Status = Transmission complete and ACK received(0)
21:04:57.403 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 8: resetResendCount initComplete=true isDead=false
21:04:57.412 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 701: Advanced to WAIT_DATA
21:04:57.420 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 8: TID 701: Transaction not completed
21:04:57.428 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=0, payload=00 08 09 8E 03 01 05 00 01 00 01 01 
21:04:57.439 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null
21:04:57.447 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 8: Application Command Request (ALIVE:DONE)
21:04:57.455 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 8: resetResendCount initComplete=true isDead=false
21:04:57.466 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 8: Incoming command class COMMAND_CLASS_MULTI_CHANNEL_ASSOCIATION, endpoint 0
21:04:57.475 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 8: SECURITY not supported
21:04:57.485 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 8: Received COMMAND_CLASS_MULTI_CHANNEL_ASSOCIATION V3 MULTI_ASSOCIATIONCMD_REPORT
21:04:57.494 [DEBUG] [ass.ZWaveMultiAssociationCommandClass] - NODE 8: association group 1 has max associations 5
21:04:57.501 [DEBUG] [ass.ZWaveMultiAssociationCommandClass] - NODE 8: Association group 1 includes the following nodes:
21:04:57.510 [DEBUG] [ass.ZWaveMultiAssociationCommandClass] - NODE 8: Associated with Node 1 in group 1
21:04:57.516 [DEBUG] [ass.ZWaveMultiAssociationCommandClass] - NODE 8: Associated with Node 1 endpoint 1 in group
21:04:57.523 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 8: Got an event from Z-Wave network: ZWaveAssociationEvent
21:04:57.536 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 8: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_ASSOCIATION, value=0
21:04:57.544 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 8: Commands processed 1.
21:04:57.552 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 8: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@6c4b06.
21:04:57.564 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 8: Command verified org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@6c4b06.
21:04:57.570 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 8: notifyTransactionResponse TID:701 DONE
21:04:57.579 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 8: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
21:04:57.586 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
21:04:57.594 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
21:04:57.600 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
21:04:57.611 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
21:05:22.755 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 05 03 20 01 00 D5 
21:05:22.769 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 03 20 01 00 
21:05:22.783 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 03 20 01 00 
21:05:22.796 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null
21:05:22.805 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 5: Application Command Request (ALIVE:DONE)
21:05:22.813 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 5: resetResendCount initComplete=true isDead=false
21:05:22.823 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 5: Incoming command class COMMAND_CLASS_BASIC, endpoint 0
21:05:22.836 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 5: SECURITY NOT required on COMMAND_CLASS_BASIC
21:05:22.845 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 5: Received COMMAND_CLASS_BASIC V1 BASIC_SET
21:05:22.853 [DEBUG] [l.commandclass.ZWaveBasicCommandClass] - NODE 5: Basic report, value = 0
21:05:22.860 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 5: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
21:05:22.865 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 5: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_BASIC, value=0
21:05:22.874 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 5: Commands processed 1.
21:05:22.881 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 5: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@b5a6e8.
21:05:22.886 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
21:05:22.895 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
21:05:22.901 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
21:05:22.910 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
21:05:23.077 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 10 00 04 00 05 0A 71 05 00 00 00 FF 07 00 00 00 68 
21:05:23.089 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 0A 71 05 00 00 00 FF 07 00 00 00 
21:05:23.101 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 0A 71 05 00 00 00 FF 07 00 00 00 
21:05:23.107 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null
21:05:23.115 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 5: Application Command Request (ALIVE:DONE)
21:05:23.122 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 5: resetResendCount initComplete=true isDead=false
21:05:23.135 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 5: Incoming command class COMMAND_CLASS_ALARM, endpoint 0
21:05:23.143 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 5: SECURITY NOT required on COMMAND_CLASS_ALARM
21:05:23.149 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 5: Received COMMAND_CLASS_ALARM V3 NOTIFICATION_REPORT
21:05:23.158 [DEBUG] [l.commandclass.ZWaveAlarmCommandClass] - NODE 5: NOTIFICATION report - 0 = 0, event=0, status=255, plen=0
21:05:23.165 [DEBUG] [l.commandclass.ZWaveAlarmCommandClass] - NODE 5: Alarm Type = BURGLAR (0)
21:05:23.174 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 5: Got an event from Z-Wave network: ZWaveAlarmValueEvent
21:05:23.181 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 5: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_ALARM, value=255
21:05:23.188 [DEBUG] [nternal.converter.ZWaveAlarmConverter] - NODE 5: Alarm converter processing NOTIFICATION
21:05:23.204 [DEBUG] [nternal.converter.ZWaveAlarmConverter] - NODE 5: Alarm converter NOTIFICATION event is 0, type OnOffType
21:05:23.212 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 5: Updating channel state zwave:device:cad84a12:node5:alarm_motion to OFF [OnOffType]
21:05:23.223 [DEBUG] [nternal.converter.ZWaveAlarmConverter] - NODE 5: Alarm converter processing NOTIFICATION
21:05:23.232 [DEBUG] [nternal.converter.ZWaveAlarmConverter] - NODE 5: Alarm converter NOTIFICATION event is 0, type OnOffType
21:05:23.240 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 5: Updating channel state zwave:device:cad84a12:node5:alarm_tamper to OFF [OnOffType]
21:05:23.251 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 5: Commands processed 1.
21:05:23.259 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 5: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@136582a.
21:05:23.271 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
21:05:23.286 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
21:05:23.298 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
21:05:23.306 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

Adding "Controller" to association group 1:

21:08:26.655 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 8: Configuration update received
21:08:26.671 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 8: Configuration update set group_1 to [controller] (ArrayList)
21:08:26.680 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 8: Association 1 consolidated to [controller]
21:08:26.688 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 8: Current members before update ZWaveAssociationGroup [index=1, name=null, profile1=null, profile2=null, associations=[node_1, node_1_1]]
21:08:26.694 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 8: Members after config update ZWaveAssociationGroup [index=1, name=null, profile1=null, profile2=null, associations=[node_1_1]]
21:08:26.702 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 8: Controller is master - forcing associations
21:08:26.725 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 8: Group is controller - forcing association
21:08:26.731 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 8: Members after controller update ZWaveAssociationGroup [index=1, name=null, profile1=null, profile2=null, associations=[node_1_1]]
21:08:26.741 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 8: Removing node_1 from association group 1
21:08:26.751 [DEBUG] [ass.ZWaveMultiAssociationCommandClass] - NODE 8: Creating new message for command MULTI_ASSOCIATIONCMD_REMOVE
21:08:26.759 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 8: SECURITY not supported
21:08:26.768 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 8: Command Class COMMAND_CLASS_MULTI_CHANNEL_ASSOCIATION is NOT required to be secured
21:08:26.775 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 8: Adding to device queue
21:08:26.783 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 8: Added 702 to queue - size 4
21:08:26.791 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
21:08:26.802 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0D 00 13 08 06 8E 04 01 00 01 00 25 49 09 
21:08:26.812 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 8: Sending REQUEST Message = 01 0D 00 13 08 06 8E 04 01 00 01 00 25 49 09 
21:08:26.819 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT
21:08:26.822 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
21:08:26.834 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
21:08:26.833 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 702: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 73
21:08:26.843 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
21:08:26.847 [DEBUG] [ass.ZWaveMultiAssociationCommandClass] - NODE 8: Creating new message for command MULTI_ASSOCIATIONCMD_GET group 1
21:08:26.844 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
21:08:26.857 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 8: SECURITY not supported
21:08:26.866 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 702: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 73
21:08:26.873 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 8: Command Class COMMAND_CLASS_MULTI_CHANNEL_ASSOCIATION is NOT required to be secured
21:08:26.868 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
21:08:26.883 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 8: Adding to device queue
21:08:26.877 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK
21:08:26.893 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 8: Added 703 to queue - size 4
21:08:26.900 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
21:08:26.906 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
21:08:26.899 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 49 00 00 02 A0 
21:08:26.918 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 702: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 73
21:08:26.927 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
21:08:26.928 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=73, payload=49 00 00 02 
21:08:26.940 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 702: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 73
21:08:26.940 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0B 00 04 00 05 05 31 05 05 01 3A FA 
21:08:26.947 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
21:08:26.960 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 8: sentData successfully placed on stack.
21:08:26.962 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 1<>127 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 05 31 05 05 01 3A 
21:08:26.968 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 702: Advanced to WAIT_REQUEST
21:08:26.978 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 8: TID 702: Transaction not completed
21:08:26.989 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (1): Message: class=SendData[19], type=Request[0], dest=0, callback=73, payload=49 00 00 02 
21:08:26.997 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 702: [WAIT_REQUEST] priority=Config, requiresResponse=true, callback: 73
21:08:27.005 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
21:08:27.016 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 702: [WAIT_REQUEST] priority=Config, requiresResponse=true, callback: 73
21:08:27.025 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking TID 702: (Callback 73)
21:08:27.033 [DEBUG] [l.serialmessage.ZWaveCommandProcessor] - Callback match!
21:08:27.042 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Correlated to TID 702: callback 73
21:08:27.064 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=73, payload=49 00 00 02 
21:08:27.074 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 8: SendData Request. CallBack ID = 73, Status = Transmission complete and ACK received(0)
21:08:27.082 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 8: resetResendCount initComplete=true isDead=false
21:08:27.091 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 702: Transaction COMPLETED
21:08:27.099 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 8: Response processed after 265ms
21:08:27.108 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 8: TID 702: Transaction completed
21:08:27.115 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 8: notifyTransactionResponse TID:702 DONE
21:08:27.124 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 8: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
21:08:27.132 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 05 31 05 05 01 3A 
21:08:27.139 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null
21:08:27.145 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 5: Application Command Request (ALIVE:DONE)
21:08:27.154 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 5: resetResendCount initComplete=true isDead=false
21:08:27.160 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 5: Incoming command class COMMAND_CLASS_SENSOR_MULTILEVEL, endpoint 0
21:08:27.166 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 5: SECURITY NOT required on COMMAND_CLASS_SENSOR_MULTILEVEL
21:08:27.172 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 5: Received COMMAND_CLASS_SENSOR_MULTILEVEL V5 SENSOR_MULTILEVEL_REPORT
21:08:27.179 [DEBUG] [ass.ZWaveMultiLevelSensorCommandClass] - NODE 5: Sensor Type = RelativeHumidity(5), Scale = 0
21:08:27.186 [DEBUG] [ass.ZWaveMultiLevelSensorCommandClass] - NODE 5: Sensor Value = 58
21:08:27.193 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 5: Got an event from Z-Wave network: ZWaveMultiLevelSensorValueEvent
21:08:27.200 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 5: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_SENSOR_MULTILEVEL, value=58
21:08:27.207 [DEBUG] [verter.ZWaveMultiLevelSensorConverter] - NODE 5: Sensor conversion not performed for RELATIVE_HUMIDITY.
21:08:27.215 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 5: Updating channel state zwave:device:cad84a12:node5:sensor_relhumidity to 58 [DecimalType]
21:08:27.226 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 5: Commands processed 1.
21:08:27.239 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 5: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@101262e.
21:08:27.255 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
21:08:27.269 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
21:08:27.277 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
21:08:27.285 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
21:08:27.297 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 08 03 8E 02 01 25 4A 0F 
21:08:27.306 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 8: Sending REQUEST Message = 01 0A 00 13 08 03 8E 02 01 25 4A 0F 
21:08:27.315 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT
21:08:27.318 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
21:08:27.327 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 703: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 74
21:08:27.336 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
21:08:27.350 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
21:08:27.351 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
21:08:27.357 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
21:08:27.365 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 703: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 74
21:08:27.371 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 4A 00 00 02 A3 
21:08:27.376 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK
21:08:27.383 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
21:08:27.387 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=74, payload=4A 00 00 02 
21:08:27.389 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 703: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 74
21:08:27.397 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
21:08:27.402 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 703: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 74
21:08:27.407 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
21:08:27.410 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0F 00 04 00 08 09 8E 03 01 05 00 01 00 01 01 7D 
21:08:27.416 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 8: sentData successfully placed on stack.
21:08:27.427 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 703: Advanced to WAIT_REQUEST
21:08:27.437 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 8: TID 703: Transaction not completed
21:08:27.440 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 1<>127 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=0, payload=00 08 09 8E 03 01 05 00 01 00 01 01 
21:08:27.447 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=74, payload=4A 00 00 02 
21:08:27.459 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 703: [WAIT_REQUEST] priority=Config, requiresResponse=true, callback: 74
21:08:27.468 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
21:08:27.475 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 703: [WAIT_REQUEST] priority=Config, requiresResponse=true, callback: 74
21:08:27.483 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking TID 703: (Callback 74)
21:08:27.489 [DEBUG] [l.serialmessage.ZWaveCommandProcessor] - Callback match!
21:08:27.495 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Correlated to TID 703: callback 74
21:08:27.501 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=74, payload=4A 00 00 02 
21:08:27.512 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 8: SendData Request. CallBack ID = 74, Status = Transmission complete and ACK received(0)
21:08:27.521 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 8: resetResendCount initComplete=true isDead=false
21:08:27.527 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 703: Advanced to WAIT_DATA
21:08:27.532 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 8: TID 703: Transaction not completed
21:08:27.540 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=0, payload=00 08 09 8E 03 01 05 00 01 00 01 01 
21:08:27.548 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null
21:08:27.553 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 8: Application Command Request (ALIVE:DONE)
21:08:27.559 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 8: resetResendCount initComplete=true isDead=false
21:08:27.565 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 8: Incoming command class COMMAND_CLASS_MULTI_CHANNEL_ASSOCIATION, endpoint 0
21:08:27.571 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 8: SECURITY not supported
21:08:27.580 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 8: Received COMMAND_CLASS_MULTI_CHANNEL_ASSOCIATION V3 MULTI_ASSOCIATIONCMD_REPORT
21:08:27.586 [DEBUG] [ass.ZWaveMultiAssociationCommandClass] - NODE 8: association group 1 has max associations 5
21:08:27.592 [DEBUG] [ass.ZWaveMultiAssociationCommandClass] - NODE 8: Association group 1 includes the following nodes:
21:08:27.597 [DEBUG] [ass.ZWaveMultiAssociationCommandClass] - NODE 8: Associated with Node 1 in group 1
21:08:27.603 [DEBUG] [ass.ZWaveMultiAssociationCommandClass] - NODE 8: Associated with Node 1 endpoint 1 in group
21:08:27.609 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 8: Got an event from Z-Wave network: ZWaveAssociationEvent
21:08:27.614 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 8: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_ASSOCIATION, value=0
21:08:27.621 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 8: Commands processed 1.
21:08:27.626 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 8: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@d28bb.
21:08:27.632 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 8: Command verified org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@d28bb.
21:08:27.637 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 8: notifyTransactionResponse TID:703 DONE
21:08:27.644 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 8: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
21:08:27.650 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
21:08:27.655 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
21:08:27.660 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
21:08:27.665 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

I can send the whole initialisation log if you tell me how to send it to you.

chris · August 24, 2019, 7:14pm

It’s not possible to remove the controller from group 1 - as I mentioned earlier, in the 2.5 binding it is forced to be set if the binding detects that the group is the lifeline. It reads this directly from the device itself.

We can see that even though you set the group as empty, it is still set to node_1_1

This is exactly the same as when you set the group to the controller -:

Generally, this looks fine - it confirms that the binding is setting the associations. The only thing to note is that the binding has used the multi-channel version of the command class. This should be fine, but may impact on the messages the device sends and could be a problem, but I can’t tell from this log.

It would be interesting to see if the device is sending anything following this - if it is I’d be interested to see what it is.

autoit · August 24, 2019, 7:28pm

You mean keep the log running for a while after these operations? For how long?

chris · August 24, 2019, 7:30pm

Yes.

I’m not sure what the device does - maybe 1 hour should be ok (??).

autoit · August 24, 2019, 7:44pm

This is right after the last log. The forum is only letting me post 48000 characters.

2019-08-24 21:08:27.665 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-08-24 21:10:43.320 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 14 00 04 00 08 0E 32 02 21 74 00 32 04 5E 00 9B 00 30 8E 92 53 
2019-08-24 21:10:43.331 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=0, payload=00 08 0E 32 02 21 74 00 32 04 5E 00 9B 00 30 8E 92 
2019-08-24 21:10:43.336 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=0, payload=00 08 0E 32 02 21 74 00 32 04 5E 00 9B 00 30 8E 92 
2019-08-24 21:10:43.339 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-08-24 21:10:43.342 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Application Command Request (ALIVE:DONE)
2019-08-24 21:10:43.345 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: resetResendCount initComplete=true isDead=false
2019-08-24 21:10:43.349 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: Incoming command class COMMAND_CLASS_METER, endpoint 0
2019-08-24 21:10:43.351 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: SECURITY not supported
2019-08-24 21:10:43.354 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 8: Received COMMAND_CLASS_METER V3 METER_REPORT
2019-08-24 21:10:43.359 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 8: Meter: Type=Electric(1), Scale=W(2), Value=3277.918
2019-08-24 21:10:43.362 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Got an event from Z-Wave network: ZWaveMeterValueEvent
2019-08-24 21:10:43.366 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_METER, value=3277.918
2019-08-24 21:10:43.369 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Updating channel state zwave:device:cad84a12:node8:meter_watts to 3277.918 [DecimalType]
2019-08-24 21:10:43.375 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Commands processed 1.
2019-08-24 21:10:43.379 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1f8f4c3.
2019-08-24 21:10:43.381 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-08-24 21:10:43.385 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-08-24 21:10:43.387 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-08-24 21:10:43.391 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-08-24 21:10:48.320 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 14 00 04 00 08 0E 32 02 21 74 00 34 D8 DF 00 05 00 32 04 5E D2 
2019-08-24 21:10:48.336 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=0, payload=00 08 0E 32 02 21 74 00 34 D8 DF 00 05 00 32 04 5E 
2019-08-24 21:10:48.341 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=0, payload=00 08 0E 32 02 21 74 00 34 D8 DF 00 05 00 32 04 5E 
2019-08-24 21:10:48.344 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-08-24 21:10:48.347 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Application Command Request (ALIVE:DONE)
2019-08-24 21:10:48.349 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: resetResendCount initComplete=true isDead=false
2019-08-24 21:10:48.352 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: Incoming command class COMMAND_CLASS_METER, endpoint 0
2019-08-24 21:10:48.355 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: SECURITY not supported
2019-08-24 21:10:48.358 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 8: Received COMMAND_CLASS_METER V3 METER_REPORT
2019-08-24 21:10:48.361 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 8: Meter: Type=Electric(1), Scale=W(2), Value=3463.391
2019-08-24 21:10:48.364 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Got an event from Z-Wave network: ZWaveMeterValueEvent
2019-08-24 21:10:48.366 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_METER, value=3463.391
2019-08-24 21:10:48.370 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Updating channel state zwave:device:cad84a12:node8:meter_watts to 3463.391 [DecimalType]
2019-08-24 21:10:48.374 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Commands processed 1.
2019-08-24 21:10:48.376 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@3fbbe.
2019-08-24 21:10:48.381 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-08-24 21:10:48.384 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-08-24 21:10:48.386 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-08-24 21:10:48.389 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-08-24 21:11:03.321 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 14 00 04 00 08 0E 32 02 21 74 00 35 F2 C3 00 0F 00 34 D8 DF B4 
2019-08-24 21:11:03.334 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=0, payload=00 08 0E 32 02 21 74 00 35 F2 C3 00 0F 00 34 D8 DF 
2019-08-24 21:11:03.341 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=0, payload=00 08 0E 32 02 21 74 00 35 F2 C3 00 0F 00 34 D8 DF 
2019-08-24 21:11:03.344 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-08-24 21:11:03.348 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Application Command Request (ALIVE:DONE)
2019-08-24 21:11:03.351 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: resetResendCount initComplete=true isDead=false
2019-08-24 21:11:03.355 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: Incoming command class COMMAND_CLASS_METER, endpoint 0
2019-08-24 21:11:03.358 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: SECURITY not supported
2019-08-24 21:11:03.361 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 8: Received COMMAND_CLASS_METER V3 METER_REPORT
2019-08-24 21:11:03.366 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 8: Meter: Type=Electric(1), Scale=W(2), Value=3535.555
2019-08-24 21:11:03.369 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Got an event from Z-Wave network: ZWaveMeterValueEvent
2019-08-24 21:11:03.373 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_METER, value=3535.555
2019-08-24 21:11:03.377 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Updating channel state zwave:device:cad84a12:node8:meter_watts to 3535.555 [DecimalType]
2019-08-24 21:11:03.382 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Commands processed 1.
2019-08-24 21:11:03.385 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@a395c6.
2019-08-24 21:11:03.390 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-08-24 21:11:03.393 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-08-24 21:11:03.396 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-08-24 21:11:03.399 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-08-24 21:11:58.546 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 05 03 20 01 00 D5 
2019-08-24 21:11:58.553 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 03 20 01 00 
2019-08-24 21:11:58.558 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 03 20 01 00 
2019-08-24 21:11:58.561 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-08-24 21:11:58.564 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Application Command Request (ALIVE:DONE)
2019-08-24 21:11:58.567 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: resetResendCount initComplete=true isDead=false
2019-08-24 21:11:58.571 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: Incoming command class COMMAND_CLASS_BASIC, endpoint 0
2019-08-24 21:11:58.574 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: SECURITY NOT required on COMMAND_CLASS_BASIC
2019-08-24 21:11:58.577 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 5: Received COMMAND_CLASS_BASIC V1 BASIC_SET
2019-08-24 21:11:58.585 [DEBUG] [.commandclass.ZWaveBasicCommandClass] - NODE 5: Basic report, value = 0
2019-08-24 21:11:58.589 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2019-08-24 21:11:58.592 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_BASIC, value=0
2019-08-24 21:11:58.596 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Commands processed 1.
2019-08-24 21:11:58.599 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@18a9c08.
2019-08-24 21:11:58.601 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-08-24 21:11:58.604 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-08-24 21:11:58.606 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-08-24 21:11:58.609 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-08-24 21:11:58.868 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 10 00 04 00 05 0A 71 05 00 00 00 FF 07 00 00 00 68 
2019-08-24 21:11:58.875 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 0A 71 05 00 00 00 FF 07 00 00 00 
2019-08-24 21:11:58.878 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 0A 71 05 00 00 00 FF 07 00 00 00 
2019-08-24 21:11:58.881 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-08-24 21:11:58.883 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Application Command Request (ALIVE:DONE)
2019-08-24 21:11:58.885 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: resetResendCount initComplete=true isDead=false
2019-08-24 21:11:58.887 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: Incoming command class COMMAND_CLASS_ALARM, endpoint 0
2019-08-24 21:11:58.890 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: SECURITY NOT required on COMMAND_CLASS_ALARM
2019-08-24 21:11:58.892 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 5: Received COMMAND_CLASS_ALARM V3 NOTIFICATION_REPORT
2019-08-24 21:11:58.895 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 5: NOTIFICATION report - 0 = 0, event=0, status=255, plen=0
2019-08-24 21:11:58.897 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 5: Alarm Type = BURGLAR (0)
2019-08-24 21:11:58.900 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got an event from Z-Wave network: ZWaveAlarmValueEvent
2019-08-24 21:11:58.902 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_ALARM, value=255
2019-08-24 21:11:58.906 [DEBUG] [ternal.converter.ZWaveAlarmConverter] - NODE 5: Alarm converter processing NOTIFICATION
2019-08-24 21:11:58.908 [DEBUG] [ternal.converter.ZWaveAlarmConverter] - NODE 5: Alarm converter NOTIFICATION event is 0, type OnOffType
2019-08-24 21:11:58.911 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Updating channel state zwave:device:cad84a12:node5:alarm_motion to OFF [OnOffType]
2019-08-24 21:11:58.916 [DEBUG] [ternal.converter.ZWaveAlarmConverter] - NODE 5: Alarm converter processing NOTIFICATION
2019-08-24 21:11:58.920 [DEBUG] [ternal.converter.ZWaveAlarmConverter] - NODE 5: Alarm converter NOTIFICATION event is 0, type OnOffType
2019-08-24 21:11:58.923 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Updating channel state zwave:device:cad84a12:node5:alarm_tamper to OFF [OnOffType]
2019-08-24 21:11:58.930 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Commands processed 1.
2019-08-24 21:11:58.932 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@b544c.
2019-08-24 21:11:58.942 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-08-24 21:11:58.945 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-08-24 21:11:58.948 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-08-24 21:11:58.951 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-08-24 21:12:58.316 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 14 00 04 00 08 0E 32 02 21 74 00 49 D6 8A 00 73 00 35 F2 C3 EE 
2019-08-24 21:12:58.327 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=0, payload=00 08 0E 32 02 21 74 00 49 D6 8A 00 73 00 35 F2 C3 
2019-08-24 21:12:58.333 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=0, payload=00 08 0E 32 02 21 74 00 49 D6 8A 00 73 00 35 F2 C3 
2019-08-24 21:12:58.336 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-08-24 21:12:58.338 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Application Command Request (ALIVE:DONE)
2019-08-24 21:12:58.341 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: resetResendCount initComplete=true isDead=false
2019-08-24 21:12:58.344 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: Incoming command class COMMAND_CLASS_METER, endpoint 0
2019-08-24 21:12:58.347 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: SECURITY not supported
2019-08-24 21:12:58.350 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 8: Received COMMAND_CLASS_METER V3 METER_REPORT
2019-08-24 21:12:58.354 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 8: Meter: Type=Electric(1), Scale=W(2), Value=4839.05
2019-08-24 21:12:58.357 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Got an event from Z-Wave network: ZWaveMeterValueEvent
2019-08-24 21:12:58.360 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_METER, value=4839.05
2019-08-24 21:12:58.364 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Updating channel state zwave:device:cad84a12:node8:meter_watts to 4839.05 [DecimalType]
2019-08-24 21:12:58.369 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Commands processed 1.
2019-08-24 21:12:58.372 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@caea2e.
2019-08-24 21:12:58.379 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-08-24 21:12:58.382 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-08-24 21:12:58.386 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-08-24 21:12:58.391 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-08-24 21:13:03.316 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 14 00 04 00 08 0E 32 02 21 74 00 38 61 0A 00 05 00 49 D6 8A CF 
2019-08-24 21:13:03.329 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=0, payload=00 08 0E 32 02 21 74 00 38 61 0A 00 05 00 49 D6 8A 
2019-08-24 21:13:03.335 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=0, payload=00 08 0E 32 02 21 74 00 38 61 0A 00 05 00 49 D6 8A 
2019-08-24 21:13:03.340 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-08-24 21:13:03.344 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Application Command Request (ALIVE:DONE)
2019-08-24 21:13:03.348 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: resetResendCount initComplete=true isDead=false
2019-08-24 21:13:03.352 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: Incoming command class COMMAND_CLASS_METER, endpoint 0
2019-08-24 21:13:03.355 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: SECURITY not supported
2019-08-24 21:13:03.359 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 8: Received COMMAND_CLASS_METER V3 METER_REPORT
2019-08-24 21:13:03.365 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 8: Meter: Type=Electric(1), Scale=W(2), Value=3694.858
2019-08-24 21:13:03.369 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Got an event from Z-Wave network: ZWaveMeterValueEvent
2019-08-24 21:13:03.373 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_METER, value=3694.858
2019-08-24 21:13:03.378 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Updating channel state zwave:device:cad84a12:node8:meter_watts to 3694.858 [DecimalType]
2019-08-24 21:13:03.383 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Commands processed 1.
2019-08-24 21:13:03.386 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@fc50d1.
2019-08-24 21:13:03.389 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-08-24 21:13:03.392 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-08-24 21:13:03.395 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-08-24 21:13:03.399 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-08-24 21:14:36.080 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 05 03 20 01 FF 2A 
2019-08-24 21:14:36.088 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 03 20 01 FF 
2019-08-24 21:14:36.093 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 03 20 01 FF 
2019-08-24 21:14:36.098 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-08-24 21:14:36.102 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Application Command Request (ALIVE:DONE)
2019-08-24 21:14:36.106 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: resetResendCount initComplete=true isDead=false
2019-08-24 21:14:36.110 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: Incoming command class COMMAND_CLASS_BASIC, endpoint 0
2019-08-24 21:14:36.114 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: SECURITY NOT required on COMMAND_CLASS_BASIC
2019-08-24 21:14:36.118 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 5: Received COMMAND_CLASS_BASIC V1 BASIC_SET
2019-08-24 21:14:36.123 [DEBUG] [.commandclass.ZWaveBasicCommandClass] - NODE 5: Basic report, value = 255
2019-08-24 21:14:36.127 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2019-08-24 21:14:36.132 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_BASIC, value=255
2019-08-24 21:14:36.137 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Commands processed 1.
2019-08-24 21:14:36.141 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@12de61a.
2019-08-24 21:14:36.145 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-08-24 21:14:36.149 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-08-24 21:14:36.153 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-08-24 21:14:36.157 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-08-24 21:14:37.444 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 10 00 04 00 05 0A 71 05 00 00 00 FF 07 08 00 00 60 
2019-08-24 21:14:37.454 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 0A 71 05 00 00 00 FF 07 08 00 00 
2019-08-24 21:14:37.460 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 0A 71 05 00 00 00 FF 07 08 00 00 
2019-08-24 21:14:37.464 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-08-24 21:14:37.467 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Application Command Request (ALIVE:DONE)
2019-08-24 21:14:37.470 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: resetResendCount initComplete=true isDead=false
2019-08-24 21:14:37.474 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: Incoming command class COMMAND_CLASS_ALARM, endpoint 0
2019-08-24 21:14:37.477 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: SECURITY NOT required on COMMAND_CLASS_ALARM
2019-08-24 21:14:37.480 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 5: Received COMMAND_CLASS_ALARM V3 NOTIFICATION_REPORT
2019-08-24 21:14:37.483 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 5: NOTIFICATION report - 0 = 0, event=8, status=255, plen=0
2019-08-24 21:14:37.486 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 5: Alarm Type = BURGLAR (0)
2019-08-24 21:14:37.490 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got an event from Z-Wave network: ZWaveAlarmValueEvent
2019-08-24 21:14:37.493 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_ALARM, value=255
2019-08-24 21:14:37.498 [DEBUG] [ternal.converter.ZWaveAlarmConverter] - NODE 5: Alarm converter processing NOTIFICATION
2019-08-24 21:14:37.501 [DEBUG] [ternal.converter.ZWaveAlarmConverter] - NODE 5: Alarm converter NOTIFICATION event is 8, type OnOffType
2019-08-24 21:14:37.505 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Updating channel state zwave:device:cad84a12:node5:alarm_motion to ON [OnOffType]
2019-08-24 21:14:37.510 [DEBUG] [ternal.converter.ZWaveAlarmConverter] - NODE 5: Alarm converter processing NOTIFICATION
2019-08-24 21:14:37.515 [DEBUG] [ternal.converter.ZWaveAlarmConverter] - NODE 5: Alarm converter NOTIFICATION event is 8, type OnOffType
2019-08-24 21:14:37.520 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Commands processed 1.
2019-08-24 21:14:37.522 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@16e6c07.
2019-08-24 21:14:37.526 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-08-24 21:14:37.530 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-08-24 21:14:37.533 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-08-24 21:14:37.536 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-08-24 21:14:53.312 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 14 00 04 00 08 0E 32 02 21 74 00 39 2A 2E 00 6E 00 38 61 0A 8C 
2019-08-24 21:14:53.325 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=0, payload=00 08 0E 32 02 21 74 00 39 2A 2E 00 6E 00 38 61 0A 
2019-08-24 21:14:53.333 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=0, payload=00 08 0E 32 02 21 74 00 39 2A 2E 00 6E 00 38 61 0A 
2019-08-24 21:14:53.336 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-08-24 21:14:53.341 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Application Command Request (ALIVE:DONE)
2019-08-24 21:14:53.344 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: resetResendCount initComplete=true isDead=false
2019-08-24 21:14:53.349 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: Incoming command class COMMAND_CLASS_METER, endpoint 0
2019-08-24 21:14:53.353 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: SECURITY not supported
2019-08-24 21:14:53.358 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 8: Received COMMAND_CLASS_METER V3 METER_REPORT
2019-08-24 21:14:53.364 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 8: Meter: Type=Electric(1), Scale=W(2), Value=3746.35
2019-08-24 21:14:53.369 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Got an event from Z-Wave network: ZWaveMeterValueEvent
2019-08-24 21:14:53.372 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_METER, value=3746.35
2019-08-24 21:14:53.379 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Updating channel state zwave:device:cad84a12:node8:meter_watts to 3746.35 [DecimalType]
2019-08-24 21:14:53.388 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Commands processed 1.
2019-08-24 21:14:53.398 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@de679e.
2019-08-24 21:14:53.402 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-08-24 21:14:53.406 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-08-24 21:14:53.411 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-08-24 21:14:53.416 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-08-24 21:15:23.312 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 14 00 04 00 08 0E 32 02 21 74 00 36 69 3B 00 1E 00 39 2A 2E CB 
2019-08-24 21:15:23.322 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=0, payload=00 08 0E 32 02 21 74 00 36 69 3B 00 1E 00 39 2A 2E 
2019-08-24 21:15:23.328 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=0, payload=00 08 0E 32 02 21 74 00 36 69 3B 00 1E 00 39 2A 2E 
2019-08-24 21:15:23.332 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-08-24 21:15:23.336 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Application Command Request (ALIVE:DONE)
2019-08-24 21:15:23.341 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: resetResendCount initComplete=true isDead=false
2019-08-24 21:15:23.346 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: Incoming command class COMMAND_CLASS_METER, endpoint 0
2019-08-24 21:15:23.350 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: SECURITY not supported
2019-08-24 21:15:23.355 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 8: Received COMMAND_CLASS_METER V3 METER_REPORT
2019-08-24 21:15:23.361 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 8: Meter: Type=Electric(1), Scale=W(2), Value=3565.883
2019-08-24 21:15:23.366 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Got an event from Z-Wave network: ZWaveMeterValueEvent
2019-08-24 21:15:23.371 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_METER, value=3565.883
2019-08-24 21:15:23.379 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Updating channel state zwave:device:cad84a12:node8:meter_watts to 3565.883 [DecimalType]
2019-08-24 21:15:23.384 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Commands processed 1.
2019-08-24 21:15:23.387 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@46cacc.
2019-08-24 21:15:23.391 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-08-24 21:15:23.393 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-08-24 21:15:23.397 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-08-24 21:15:23.400 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-08-24 21:15:28.311 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 14 00 04 00 08 0E 32 02 21 74 00 32 4F F6 00 05 00 36 69 3B 66 
2019-08-24 21:15:28.322 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=0, payload=00 08 0E 32 02 21 74 00 32 4F F6 00 05 00 36 69 3B 
2019-08-24 21:15:28.334 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=0, payload=00 08 0E 32 02 21 74 00 32 4F F6 00 05 00 36 69 3B 
2019-08-24 21:15:28.337 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-08-24 21:15:28.341 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Application Command Request (ALIVE:DONE)
2019-08-24 21:15:28.344 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: resetResendCount initComplete=true isDead=false
2019-08-24 21:15:28.349 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: Incoming command class COMMAND_CLASS_METER, endpoint 0
2019-08-24 21:15:28.352 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: SECURITY not supported
2019-08-24 21:15:28.356 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 8: Received COMMAND_CLASS_METER V3 METER_REPORT
2019-08-24 21:15:28.360 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 8: Meter: Type=Electric(1), Scale=W(2), Value=3297.27
2019-08-24 21:15:28.365 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Got an event from Z-Wave network: ZWaveMeterValueEvent
2019-08-24 21:15:28.368 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_METER, value=3297.27
2019-08-24 21:15:28.373 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Updating channel state zwave:device:cad84a12:node8:meter_watts to 3297.27 [DecimalType]
2019-08-24 21:15:28.380 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Commands processed 1.
2019-08-24 21:15:28.383 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@8ff2e8.
2019-08-24 21:15:28.394 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-08-24 21:15:28.400 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-08-24 21:15:28.403 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-08-24 21:15:28.409 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-08-24 21:17:47.531 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 10 00 04 00 05 0A 71 05 00 00 00 FF 07 00 00 00 68 
2019-08-24 21:17:47.548 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 0A 71 05 00 00 00 FF 07 00 00 00 
2019-08-24 21:17:47.558 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 0A 71 05 00 00 00 FF 07 00 00 00 
2019-08-24 21:17:47.564 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-08-24 21:17:47.569 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Application Command Request (ALIVE:DONE)
2019-08-24 21:17:47.574 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: resetResendCount initComplete=true isDead=false
2019-08-24 21:17:47.580 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: Incoming command class COMMAND_CLASS_ALARM, endpoint 0
2019-08-24 21:17:47.586 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: SECURITY NOT required on COMMAND_CLASS_ALARM
2019-08-24 21:17:47.590 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 5: Received COMMAND_CLASS_ALARM V3 NOTIFICATION_REPORT
2019-08-24 21:17:47.596 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 5: NOTIFICATION report - 0 = 0, event=0, status=255, plen=0
2019-08-24 21:17:47.600 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 5: Alarm Type = BURGLAR (0)
2019-08-24 21:17:47.605 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got an event from Z-Wave network: ZWaveAlarmValueEvent
2019-08-24 21:17:47.610 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_ALARM, value=255
2019-08-24 21:17:47.616 [DEBUG] [ternal.converter.ZWaveAlarmConverter] - NODE 5: Alarm converter processing NOTIFICATION
2019-08-24 21:17:47.620 [DEBUG] [ternal.converter.ZWaveAlarmConverter] - NODE 5: Alarm converter NOTIFICATION event is 0, type OnOffType
2019-08-24 21:17:47.626 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Updating channel state zwave:device:cad84a12:node5:alarm_motion to OFF [OnOffType]
2019-08-24 21:17:47.632 [DEBUG] [ternal.converter.ZWaveAlarmConverter] - NODE 5: Alarm converter processing NOTIFICATION
2019-08-24 21:17:47.636 [DEBUG] [ternal.converter.ZWaveAlarmConverter] - NODE 5: Alarm converter NOTIFICATION event is 0, type OnOffType
2019-08-24 21:17:47.639 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Updating channel state zwave:device:cad84a12:node5:alarm_tamper to OFF [OnOffType]
2019-08-24 21:17:47.646 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Commands processed 1.
2019-08-24 21:17:47.649 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@a3a12a.
2019-08-24 21:17:47.654 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-08-24 21:17:47.656 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-08-24 21:17:47.659 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-08-24 21:17:47.663 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-08-24 21:17:50.022 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 05 03 20 01 00 D5 
2019-08-24 21:17:50.037 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 03 20 01 00 
2019-08-24 21:17:50.042 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 03 20 01 00 
2019-08-24 21:17:50.046 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-08-24 21:17:50.049 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Application Command Request (ALIVE:DONE)
2019-08-24 21:17:50.053 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: resetResendCount initComplete=true isDead=false
2019-08-24 21:17:50.056 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: Incoming command class COMMAND_CLASS_BASIC, endpoint 0
2019-08-24 21:17:50.060 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: SECURITY NOT required on COMMAND_CLASS_BASIC
2019-08-24 21:17:50.063 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 5: Received COMMAND_CLASS_BASIC V1 BASIC_SET
2019-08-24 21:17:50.067 [DEBUG] [.commandclass.ZWaveBasicCommandClass] - NODE 5: Basic report, value = 0
2019-08-24 21:17:50.069 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2019-08-24 21:17:50.072 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_BASIC, value=0
2019-08-24 21:17:50.075 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Commands processed 1.
2019-08-24 21:17:50.078 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1c8d9f7.
2019-08-24 21:17:50.080 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-08-24 21:17:50.083 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-08-24 21:17:50.085 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-08-24 21:17:50.088 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-08-24 21:18:18.308 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 14 00 04 00 08 0E 32 02 21 74 00 02 93 74 00 AA 00 32 4F F6 48 
2019-08-24 21:18:18.320 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=0, payload=00 08 0E 32 02 21 74 00 02 93 74 00 AA 00 32 4F F6 
2019-08-24 21:18:18.326 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=0, payload=00 08 0E 32 02 21 74 00 02 93 74 00 AA 00 32 4F F6 
2019-08-24 21:18:18.329 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-08-24 21:18:18.333 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Application Command Request (ALIVE:DONE)
2019-08-24 21:18:18.341 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: resetResendCount initComplete=true isDead=false
2019-08-24 21:18:18.345 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: Incoming command class COMMAND_CLASS_METER, endpoint 0
2019-08-24 21:18:18.348 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: SECURITY not supported
2019-08-24 21:18:18.351 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 8: Received COMMAND_CLASS_METER V3 METER_REPORT
2019-08-24 21:18:18.355 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 8: Meter: Type=Electric(1), Scale=W(2), Value=168.82
2019-08-24 21:18:18.358 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Got an event from Z-Wave network: ZWaveMeterValueEvent
2019-08-24 21:18:18.361 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_METER, value=168.82
2019-08-24 21:18:18.365 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Updating channel state zwave:device:cad84a12:node8:meter_watts to 168.82 [DecimalType]
2019-08-24 21:18:18.370 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Commands processed 1.
2019-08-24 21:18:18.375 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1767f68.
2019-08-24 21:18:18.382 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-08-24 21:18:18.385 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-08-24 21:18:18.389 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-08-24 21:18:18.393 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-08-24 21:18:23.307 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 14 00 04 00 08 0E 32 02 21 74 00 02 EA 0E 00 05 00 02 93 74 8A 
2019-08-24 21:18:23.318 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=0, payload=00 08 0E 32 02 21 74 00 02 EA 0E 00 05 00 02 93 74 
2019-08-24 21:18:23.325 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=0, payload=00 08 0E 32 02 21 74 00 02 EA 0E 00 05 00 02 93 74 
2019-08-24 21:18:23.330 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-08-24 21:18:23.335 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Application Command Request (ALIVE:DONE)
2019-08-24 21:18:23.340 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: resetResendCount initComplete=true isDead=false
2019-08-24 21:18:23.346 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: Incoming command class COMMAND_CLASS_METER, endpoint 0
2019-08-24 21:18:23.351 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: SECURITY not supported
2019-08-24 21:18:23.357 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 8: Received COMMAND_CLASS_METER V3 METER_REPORT
2019-08-24 21:18:23.364 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 8: Meter: Type=Electric(1), Scale=W(2), Value=190.99
2019-08-24 21:18:23.370 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Got an event from Z-Wave network: ZWaveMeterValueEvent
2019-08-24 21:18:23.376 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_METER, value=190.99
2019-08-24 21:18:23.381 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Updating channel state zwave:device:cad84a12:node8:meter_watts to 190.99 [DecimalType]
2019-08-24 21:18:23.388 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Commands processed 1.
2019-08-24 21:18:23.393 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@5ddc1c.
2019-08-24 21:18:23.396 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-08-24 21:18:23.401 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-08-24 21:18:23.404 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-08-24 21:18:23.411 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

chris · August 24, 2019, 7:54pm

This looks ok -:

This shows the device sending meter reports between a few seconds up to a couple of minutes apart - I guess depending on the amount of change between each reading.

Is this what you are expecting, or is something missing?

autoit · August 24, 2019, 8:05pm

This is what I’m expecting. Everything has been working ok ever since making the association with the Z-Wave PC Controller software.

If we can’t find anything strange with these logs, I’m guessing the “problem” is that the original problem was already fixed. If that is the case, the troubleshooting should continue with someone who has a new HEM without any modifications - or if I encounter problems with this unit in the future.

chris · August 24, 2019, 8:15pm

Well, let’s see how it goes. There may be some issues with the use of the multi-channel association. This is a really messy area of ZWave as it has evolved continually over the past few years and there are now a lot of different implementations out there doing various different things (compliant and not!)

chris · August 25, 2019, 10:12am

I will update the database to remove groups 2 and 3 to make it consistent with the documentation and discussion above. If this is incorrect for some devices, then it might mean there are different versions, and in this case we will need to add a new database entry.

pstapf · January 12, 2020, 1:20pm

I bought a Aeotec HEM Gen5 in December just for my fresh install of openHAB 2.5.0 via the openhabian image.
Can’t get the HEM working to send autmatic reports like all the users within this thread.
I followed the solution to implement a rules sending “REFRESH” command every 10secs.
But it would be great to get it working to send automatic reports.

I disabled “selective reporting” (Parameter 3) and set interval to 5 secs, and parameter 101 to 2097152

Tried also different other setting via PaperUI and HABmin but without success.

Sadly it seems to me I cannot use this zensys tool because of a missing zwave usb stick, I’m using the razberry zwave.me controller for the extension slot of my raspberry pi.

So what can I do ?
I’m quite new to openhab (just 2 weeks of knowlege) so I should provide something please provide me the one or other link if possible for example to send the correct logs.

thanks in advance
Peter

abol3z · January 14, 2020, 12:17pm

Hi @chris

I’ve installed my device today and I faced the same problem, the reports are not getting updated unless I send a REFRESH command to one of the items.

I am running openhab 2.5.0 stable

chris · January 14, 2020, 12:33pm

Please check the configuration of your device. Common problems are that the associations are not set correctly.

abol3z · January 14, 2020, 1:02pm

Sure, I checked all configs and they should be correct. See below

I believe it is the same as what others have reported in this thread.

chris · January 14, 2020, 2:13pm

Please provide a log showing what the binding is receiving.

abol3z · January 14, 2020, 2:25pm

What operation should I do while logging?
Currently the log shows nothing at all until I send a REFRESH command.

I also found that configuring the binding_pollperiod can help instead of sending a REFRESH command using rules, it feels more consistent to me.

5iver · January 14, 2020, 3:25pm

That image shows the lifeline being set, but what about the report groups? Sometimes it helps to clear them out, save, and then reconfigure the associations.

chris · January 14, 2020, 3:32pm

Do nothing. I just want to see what the device is sending when there is no polling.

abol3z · January 15, 2020, 10:18am

Tried to change them multiple times, nothing changed.

abol3z · January 15, 2020, 10:21am

Please find the log attached zwave.log (428.8 KB)

The device is question is NODE 40, and it appears that it is not communicating anything between polling period, which is 10mins.

chris · January 15, 2020, 10:24am

If it is not sending anything, then this means that there is a device configuration issue, or the packets are getting lost somehow. If the binding doesn’t receive anything, then it cannot update the information in the UI.

Typically, you should not need to set the report groups, although I don’t know this specific device. The lifeline should in theory provide all information a gateway needs.

Do you have a debug log I can look at for this?