2020-11-24 17:09:04.002 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 30: Configuration update received 2020-11-24 17:09:04.009 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 30: Configuration update set group_3 to [] (EmptyList) 2020-11-24 17:09:04.012 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 30: Association 3 consolidated to [] 2020-11-24 17:09:04.016 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 30: Current members before update ZWaveAssociationGroup [index=3, name=null, profile1=null, profile2=null, associations=[node_1]] 2020-11-24 17:09:04.019 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 30: Members after config update ZWaveAssociationGroup [index=3, name=null, profile1=null, profile2=null, associations=[]] 2020-11-24 17:09:04.022 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 30: Controller is master - forcing associations 2020-11-24 17:09:04.047 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 30: Group is controller - forcing association 2020-11-24 17:09:04.050 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 30: Members after controller update ZWaveAssociationGroup [index=3, name=null, profile1=null, profile2=null, associations=[node_1_1]] 2020-11-24 17:09:04.053 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 30: Removing node_1 from association group 3 2020-11-24 17:09:04.056 [DEBUG] [ndclass.ZWaveAssociationCommandClass] - NODE 30: Creating new message for application command ASSOCIATIONCMD_REMOVE group=3, node=1 2020-11-24 17:09:04.059 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 30: SECURITY NOT required on COMMAND_CLASS_ASSOCIATION 2020-11-24 17:09:04.062 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 30: Command Class COMMAND_CLASS_ASSOCIATION is NOT required to be secured 2020-11-24 17:09:04.065 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 30: Adding to device queue 2020-11-24 17:09:04.068 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 30: Added 1474 to queue - size 2 2020-11-24 17:09:04.071 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-11-24 17:09:04.075 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0B 00 13 1E 04 85 04 03 01 25 74 2F 2020-11-24 17:09:04.080 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 30: Sending REQUEST Message = 01 0B 00 13 1E 04 85 04 03 01 25 74 2F 2020-11-24 17:09:04.083 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-11-24 17:09:04.085 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-11-24 17:09:04.086 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 1474: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 116 2020-11-24 17:09:04.087 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-11-24 17:09:04.089 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-11-24 17:09:04.090 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 30: Adding node_1_1 to association group 3 2020-11-24 17:09:04.091 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 1474: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 116 2020-11-24 17:09:04.092 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-11-24 17:09:04.092 [DEBUG] [ndclass.ZWaveAssociationCommandClass] - NODE 30: Creating new message for application command ASSOCIATIONCMD_SET, group=3, node=1 2020-11-24 17:09:04.093 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-11-24 17:09:04.094 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 30: SECURITY NOT required on COMMAND_CLASS_ASSOCIATION 2020-11-24 17:09:04.094 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-11-24 17:09:04.097 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 30: Command Class COMMAND_CLASS_ASSOCIATION is NOT required to be secured 2020-11-24 17:09:04.099 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 2020-11-24 17:09:04.100 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 30: Adding to device queue 2020-11-24 17:09:04.102 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2020-11-24 17:09:04.103 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 30: Added 1475 to queue - size 2 2020-11-24 17:09:04.105 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2020-11-24 17:09:04.106 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 1474: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 116 2020-11-24 17:09:04.106 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-11-24 17:09:04.109 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-11-24 17:09:04.111 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 74 00 00 02 9D 2020-11-24 17:09:04.111 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 1474: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 116 2020-11-24 17:09:04.113 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2020-11-24 17:09:04.113 [DEBUG] [ndclass.ZWaveAssociationCommandClass] - NODE 30: Creating new message for application command ASSOCIATIONCMD_GET group 3 2020-11-24 17:09:04.115 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=116, payload=74 00 00 02 2020-11-24 17:09:04.115 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 30: sentData successfully placed on stack. 2020-11-24 17:09:04.117 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 30: SECURITY NOT required on COMMAND_CLASS_ASSOCIATION 2020-11-24 17:09:04.118 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 1474: Advanced to WAIT_REQUEST 2020-11-24 17:09:04.120 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 30: TID 1474: Transaction not completed 2020-11-24 17:09:04.120 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 30: Command Class COMMAND_CLASS_ASSOCIATION is NOT required to be secured 2020-11-24 17:09:04.123 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=116, payload=74 00 00 02 2020-11-24 17:09:04.123 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 30: Adding to device queue 2020-11-24 17:09:04.125 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 1474: [WAIT_REQUEST] priority=Config, requiresResponse=true, callback: 116 2020-11-24 17:09:04.126 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 30: Added 1476 to queue - size 3 2020-11-24 17:09:04.128 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-11-24 17:09:04.131 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-11-24 17:09:04.131 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 30: Configuration update set group_2 to [] (EmptyList) 2020-11-24 17:09:04.132 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 1474: [WAIT_REQUEST] priority=Config, requiresResponse=true, callback: 116 2020-11-24 17:09:04.133 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 30: Association 2 consolidated to [] 2020-11-24 17:09:04.134 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 1474: (Callback 116) 2020-11-24 17:09:04.136 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match! 2020-11-24 17:09:04.136 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 30: Current members before update ZWaveAssociationGroup [index=2, name=null, profile1=null, profile2=null, associations=[node_1]] 2020-11-24 17:09:04.138 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 1474: callback 116 2020-11-24 17:09:04.138 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 30: Members after config update ZWaveAssociationGroup [index=2, name=null, profile1=null, profile2=null, associations=[]] 2020-11-24 17:09:04.140 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=116, payload=74 00 00 02 2020-11-24 17:09:04.140 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 30: Controller is master - forcing associations 2020-11-24 17:09:04.142 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 30: SendData Request. CallBack ID = 116, Status = Transmission complete and ACK received(0) 2020-11-24 17:09:04.144 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 30: resetResendCount initComplete=true isDead=false 2020-11-24 17:09:04.147 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 1474: Transaction COMPLETED 2020-11-24 17:09:04.148 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 30: Response processed after 62ms 2020-11-24 17:09:04.151 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 30: TID 1474: Transaction completed 2020-11-24 17:09:04.152 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 30: notifyTransactionResponse TID:1474 DONE 2020-11-24 17:09:04.155 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 30: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 2020-11-24 17:09:04.157 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-11-24 17:09:04.159 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-11-24 17:09:04.159 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 30: Group is controller - forcing association 2020-11-24 17:09:04.163 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0B 00 13 1E 04 85 01 03 01 25 75 2B 2020-11-24 17:09:04.162 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 30: Members after controller update ZWaveAssociationGroup [index=2, name=null, profile1=null, profile2=null, associations=[node_1_1]] 2020-11-24 17:09:04.165 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 30: Removing node_1 from association group 2 2020-11-24 17:09:04.166 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 30: Sending REQUEST Message = 01 0B 00 13 1E 04 85 01 03 01 25 75 2B 2020-11-24 17:09:04.168 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-11-24 17:09:04.168 [DEBUG] [ndclass.ZWaveAssociationCommandClass] - NODE 30: Creating new message for application command ASSOCIATIONCMD_REMOVE group=2, node=1 2020-11-24 17:09:04.169 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-11-24 17:09:04.169 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 1475: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 117 2020-11-24 17:09:04.171 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-11-24 17:09:04.171 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 30: SECURITY NOT required on COMMAND_CLASS_ASSOCIATION 2020-11-24 17:09:04.173 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-11-24 17:09:04.175 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 1475: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 117 2020-11-24 17:09:04.174 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 30: Command Class COMMAND_CLASS_ASSOCIATION is NOT required to be secured 2020-11-24 17:09:04.177 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 2020-11-24 17:09:04.177 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-11-24 17:09:04.177 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 30: Adding to device queue 2020-11-24 17:09:04.179 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-11-24 17:09:04.180 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2020-11-24 17:09:04.181 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 30: Added 1477 to queue - size 3 2020-11-24 17:09:04.186 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-11-24 17:09:04.193 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 75 00 00 02 9C 2020-11-24 17:09:04.197 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 1<>127 : Message: class=SendData[19], type=Request[0], dest=0, callback=117, payload=75 00 00 02 2020-11-24 17:09:04.197 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-11-24 17:09:04.190 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 30: Adding node_1_1 to association group 2 2020-11-24 17:09:04.200 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (1): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2020-11-24 17:09:04.200 [DEBUG] [ndclass.ZWaveAssociationCommandClass] - NODE 30: Creating new message for application command ASSOCIATIONCMD_SET, group=2, node=1 2020-11-24 17:09:04.202 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 1475: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 117 2020-11-24 17:09:04.205 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-11-24 17:09:04.204 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 30: SECURITY NOT required on COMMAND_CLASS_ASSOCIATION 2020-11-24 17:09:04.206 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 1475: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 117 2020-11-24 17:09:04.207 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 30: Command Class COMMAND_CLASS_ASSOCIATION is NOT required to be secured 2020-11-24 17:09:04.209 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2020-11-24 17:09:04.211 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 30: sentData successfully placed on stack. 2020-11-24 17:09:04.210 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 30: Adding to device queue 2020-11-24 17:09:04.213 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 1475: Advanced to WAIT_REQUEST 2020-11-24 17:09:04.213 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 30: Added 1478 to queue - size 4 2020-11-24 17:09:04.216 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 30: TID 1475: Transaction not completed 2020-11-24 17:09:04.216 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-11-24 17:09:04.219 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=117, payload=75 00 00 02 2020-11-24 17:09:04.222 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 1475: [WAIT_REQUEST] priority=Config, requiresResponse=true, callback: 117 2020-11-24 17:09:04.221 [DEBUG] [ndclass.ZWaveAssociationCommandClass] - NODE 30: Creating new message for application command ASSOCIATIONCMD_GET group 2 2020-11-24 17:09:04.224 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-11-24 17:09:04.225 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 30: SECURITY NOT required on COMMAND_CLASS_ASSOCIATION 2020-11-24 17:09:04.231 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 1475: [WAIT_REQUEST] priority=Config, requiresResponse=true, callback: 117 2020-11-24 17:09:04.231 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 30: Command Class COMMAND_CLASS_ASSOCIATION is NOT required to be secured 2020-11-24 17:09:04.234 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 1475: (Callback 117) 2020-11-24 17:09:04.237 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match! 2020-11-24 17:09:04.240 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 1475: callback 117 2020-11-24 17:09:04.242 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=117, payload=75 00 00 02 2020-11-24 17:09:04.242 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 30: Adding to device queue 2020-11-24 17:09:04.245 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 30: SendData Request. CallBack ID = 117, Status = Transmission complete and ACK received(0) 2020-11-24 17:09:04.245 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 30: Added 1479 to queue - size 5 2020-11-24 17:09:04.247 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 30: resetResendCount initComplete=true isDead=false 2020-11-24 17:09:04.247 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-11-24 17:09:04.249 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 1475: Transaction COMPLETED 2020-11-24 17:09:04.251 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 30: Response processed after 82ms 2020-11-24 17:09:04.252 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 30: TID 1475: Transaction completed 2020-11-24 17:09:04.255 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 30: notifyTransactionResponse TID:1475 DONE 2020-11-24 17:09:04.257 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 30: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 2020-11-24 17:09:04.258 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-11-24 17:09:04.260 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-11-24 17:09:04.263 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 1E 03 85 02 03 25 76 2C 2020-11-24 17:09:04.265 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 30: Sending REQUEST Message = 01 0A 00 13 1E 03 85 02 03 25 76 2C 2020-11-24 17:09:04.267 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-11-24 17:09:04.269 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 1476: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 118 2020-11-24 17:09:04.269 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-11-24 17:09:04.270 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-11-24 17:09:04.272 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-11-24 17:09:04.274 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 1476: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 118 2020-11-24 17:09:04.275 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-11-24 17:09:04.276 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 2020-11-24 17:09:04.277 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-11-24 17:09:04.278 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-11-24 17:09:04.281 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2020-11-24 17:09:04.284 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2020-11-24 17:09:04.285 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 1476: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 118 2020-11-24 17:09:04.287 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-11-24 17:09:04.289 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 1476: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 118 2020-11-24 17:09:04.292 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 76 00 00 02 9F 2020-11-24 17:09:04.301 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=118, payload=76 00 00 02 2020-11-24 17:09:04.303 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2020-11-24 17:09:04.305 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 30: sentData successfully placed on stack. 2020-11-24 17:09:04.308 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0C 00 04 00 1E 06 85 03 03 05 00 01 6E 2020-11-24 17:09:04.309 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 1476: Advanced to WAIT_REQUEST 2020-11-24 17:09:04.311 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 30: TID 1476: Transaction not completed 2020-11-24 17:09:04.313 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 1<>127 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=30, callback=0, payload=00 1E 06 85 03 03 05 00 01 2020-11-24 17:09:04.314 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=118, payload=76 00 00 02 2020-11-24 17:09:04.316 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 1476: [WAIT_REQUEST] priority=Config, requiresResponse=true, callback: 118 2020-11-24 17:09:04.320 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-11-24 17:09:04.322 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 1476: [WAIT_REQUEST] priority=Config, requiresResponse=true, callback: 118 2020-11-24 17:09:04.324 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 1476: (Callback 118) 2020-11-24 17:09:04.326 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match! 2020-11-24 17:09:04.328 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 1476: callback 118 2020-11-24 17:09:04.331 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=118, payload=76 00 00 02 2020-11-24 17:09:04.332 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 30: SendData Request. CallBack ID = 118, Status = Transmission complete and ACK received(0) 2020-11-24 17:09:04.335 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 30: resetResendCount initComplete=true isDead=false 2020-11-24 17:09:04.336 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 1476: Advanced to WAIT_DATA 2020-11-24 17:09:04.338 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 30: TID 1476: Transaction not completed 2020-11-24 17:09:04.340 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=30, callback=0, payload=00 1E 06 85 03 03 05 00 01 2020-11-24 17:09:04.342 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2020-11-24 17:09:04.344 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 30: Application Command Request (ALIVE:DONE) 2020-11-24 17:09:04.345 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 30: resetResendCount initComplete=true isDead=false 2020-11-24 17:09:04.347 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 30: Incoming command class COMMAND_CLASS_ASSOCIATION, endpoint 0 2020-11-24 17:09:04.349 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 30: SECURITY NOT required on COMMAND_CLASS_ASSOCIATION 2020-11-24 17:09:04.350 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 30: Received COMMAND_CLASS_ASSOCIATION V2 ASSOCIATIONCMD_REPORT 2020-11-24 17:09:04.352 [DEBUG] [ndclass.ZWaveAssociationCommandClass] - NODE 30: association group 3 has max associations 5 2020-11-24 17:09:04.353 [DEBUG] [ndclass.ZWaveAssociationCommandClass] - NODE 30: association group 3 includes the following nodes: 2020-11-24 17:09:04.355 [DEBUG] [ndclass.ZWaveAssociationCommandClass] - Node 1 2020-11-24 17:09:04.357 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 30: Got an event from Z-Wave network: ZWaveAssociationEvent 2020-11-24 17:09:04.359 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 30: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_ASSOCIATION, value=0 2020-11-24 17:09:04.361 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 30: Commands processed 1. 2020-11-24 17:09:04.362 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 30: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@7d0aca. 2020-11-24 17:09:04.363 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 30: Command verified org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@7d0aca. 2020-11-24 17:09:04.365 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 30: notifyTransactionResponse TID:1476 DONE 2020-11-24 17:09:04.366 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 30: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 2020-11-24 17:09:04.368 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1 2020-11-24 17:09:04.369 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2020-11-24 17:09:04.370 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-11-24 17:09:04.372 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-11-24 17:09:04.374 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0B 00 13 1E 04 85 04 02 01 25 77 2D 2020-11-24 17:09:04.377 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 30: Sending REQUEST Message = 01 0B 00 13 1E 04 85 04 02 01 25 77 2D 2020-11-24 17:09:04.378 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-11-24 17:09:04.380 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-11-24 17:09:04.381 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 1477: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 119 2020-11-24 17:09:04.382 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-11-24 17:09:04.383 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-11-24 17:09:04.385 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 1477: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 119 2020-11-24 17:09:04.387 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 2020-11-24 17:09:04.389 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-11-24 17:09:04.390 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-11-24 17:09:04.390 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2020-11-24 17:09:04.392 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-11-24 17:09:04.394 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2020-11-24 17:09:04.395 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 1477: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 119 2020-11-24 17:09:04.396 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-11-24 17:09:04.398 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 1477: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 119 2020-11-24 17:09:04.400 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2020-11-24 17:09:04.401 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 30: sentData successfully placed on stack. 2020-11-24 17:09:04.403 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 1477: Advanced to WAIT_REQUEST 2020-11-24 17:09:04.404 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 77 00 00 02 9E 2020-11-24 17:09:04.405 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 30: TID 1477: Transaction not completed 2020-11-24 17:09:04.406 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-11-24 17:09:04.407 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=119, payload=77 00 00 02 2020-11-24 17:09:04.408 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-11-24 17:09:04.410 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=119, payload=77 00 00 02 2020-11-24 17:09:04.411 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 1477: [WAIT_REQUEST] priority=Config, requiresResponse=true, callback: 119 2020-11-24 17:09:04.413 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-11-24 17:09:04.414 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 1477: [WAIT_REQUEST] priority=Config, requiresResponse=true, callback: 119 2020-11-24 17:09:04.416 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 1477: (Callback 119) 2020-11-24 17:09:04.417 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match! 2020-11-24 17:09:04.419 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 1477: callback 119 2020-11-24 17:09:04.421 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=119, payload=77 00 00 02 2020-11-24 17:09:04.422 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 30: SendData Request. CallBack ID = 119, Status = Transmission complete and ACK received(0) 2020-11-24 17:09:04.424 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 30: resetResendCount initComplete=true isDead=false 2020-11-24 17:09:04.425 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 1477: Transaction COMPLETED 2020-11-24 17:09:04.427 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 30: Response processed after 45ms 2020-11-24 17:09:04.428 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 30: TID 1477: Transaction completed 2020-11-24 17:09:04.429 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 30: notifyTransactionResponse TID:1477 DONE 2020-11-24 17:09:04.431 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 30: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 2020-11-24 17:09:04.432 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-11-24 17:09:04.434 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-11-24 17:09:04.437 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0B 00 13 1E 04 85 01 02 01 25 78 27 2020-11-24 17:09:04.440 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 30: Sending REQUEST Message = 01 0B 00 13 1E 04 85 01 02 01 25 78 27 2020-11-24 17:09:04.441 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-11-24 17:09:04.443 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-11-24 17:09:04.443 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 1478: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 120 2020-11-24 17:09:04.444 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-11-24 17:09:04.446 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-11-24 17:09:04.447 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 1478: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 120 2020-11-24 17:09:04.448 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-11-24 17:09:04.450 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 2020-11-24 17:09:04.450 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty ==> /var/log/openhab2/events.log <== 2020-11-24 17:09:04.277 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:5727c0c5:node30' has been updated. 2020-11-24 17:09:04.281 [vent.ConfigStatusInfoEvent] - ConfigStatusInfo [configStatusMessages=[ConfigStatusMessage [parameterName=group_3, type=PENDING, messageKey=null, arguments=null, message=null, statusCode=null], ConfigStatusMessage [parameterName=group_2, type=PENDING, messageKey=null, arguments=null, message=null, statusCode=null]]] ==> /var/log/openhab2/openhab.log <== 2020-11-24 17:09:04.452 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-11-24 17:09:04.453 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2020-11-24 17:09:04.455 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2020-11-24 17:09:04.457 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 1478: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 120 2020-11-24 17:09:04.459 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-11-24 17:09:04.461 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 1478: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 120 2020-11-24 17:09:04.463 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2020-11-24 17:09:04.465 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 30: sentData successfully placed on stack. 2020-11-24 17:09:04.466 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 78 00 00 02 91 2020-11-24 17:09:04.467 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 1478: Advanced to WAIT_REQUEST 2020-11-24 17:09:04.469 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 30: TID 1478: Transaction not completed 2020-11-24 17:09:04.470 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-11-24 17:09:04.470 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=120, payload=78 00 00 02 2020-11-24 17:09:04.472 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-11-24 17:09:04.474 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=120, payload=78 00 00 02 2020-11-24 17:09:04.476 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 1478: [WAIT_REQUEST] priority=Config, requiresResponse=true, callback: 120 2020-11-24 17:09:04.477 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-11-24 17:09:04.478 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 1478: [WAIT_REQUEST] priority=Config, requiresResponse=true, callback: 120 2020-11-24 17:09:04.481 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 1478: (Callback 120) 2020-11-24 17:09:04.482 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match! 2020-11-24 17:09:04.485 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 1478: callback 120 2020-11-24 17:09:04.487 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=120, payload=78 00 00 02 2020-11-24 17:09:04.489 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 30: SendData Request. CallBack ID = 120, Status = Transmission complete and ACK received(0) 2020-11-24 17:09:04.491 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 30: resetResendCount initComplete=true isDead=false 2020-11-24 17:09:04.493 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 1478: Transaction COMPLETED 2020-11-24 17:09:04.495 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 30: Response processed after 52ms 2020-11-24 17:09:04.497 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 30: TID 1478: Transaction completed 2020-11-24 17:09:04.499 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 30: notifyTransactionResponse TID:1478 DONE 2020-11-24 17:09:04.501 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 30: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 2020-11-24 17:09:04.503 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-11-24 17:09:04.505 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-11-24 17:09:04.508 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 1E 03 85 02 02 25 79 22 2020-11-24 17:09:04.511 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 30: Sending REQUEST Message = 01 0A 00 13 1E 03 85 02 02 25 79 22 2020-11-24 17:09:04.513 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-11-24 17:09:04.514 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-11-24 17:09:04.516 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 1479: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 121 2020-11-24 17:09:04.516 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-11-24 17:09:04.518 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-11-24 17:09:04.520 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 1479: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 121 2020-11-24 17:09:04.521 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 2020-11-24 17:09:04.522 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-11-24 17:09:04.524 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2020-11-24 17:09:04.524 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-11-24 17:09:04.526 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-11-24 17:09:04.529 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2020-11-24 17:09:04.531 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 1479: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 121 2020-11-24 17:09:04.533 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-11-24 17:09:04.535 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 1479: [WAIT_RESPONSE] priority=Config, requiresResponse=true, callback: 121 2020-11-24 17:09:04.537 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2020-11-24 17:09:04.539 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 30: sentData successfully placed on stack. 2020-11-24 17:09:04.541 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 79 00 00 03 91 2020-11-24 17:09:04.541 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 1479: Advanced to WAIT_REQUEST 2020-11-24 17:09:04.544 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=121, payload=79 00 00 03 2020-11-24 17:09:04.546 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 30: TID 1479: Transaction not completed 2020-11-24 17:09:04.548 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=121, payload=79 00 00 03 2020-11-24 17:09:04.550 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 1479: [WAIT_REQUEST] priority=Config, requiresResponse=true, callback: 121 2020-11-24 17:09:04.552 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-11-24 17:09:04.554 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0C 00 04 00 1E 06 85 03 02 05 00 01 6F 2020-11-24 17:09:04.555 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 1479: [WAIT_REQUEST] priority=Config, requiresResponse=true, callback: 121 2020-11-24 17:09:04.558 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=30, callback=0, payload=00 1E 06 85 03 02 05 00 01 2020-11-24 17:09:04.559 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 1479: (Callback 121) 2020-11-24 17:09:04.561 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match! 2020-11-24 17:09:04.563 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 1479: callback 121 2020-11-24 17:09:04.566 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=121, payload=79 00 00 03 2020-11-24 17:09:04.568 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 30: SendData Request. CallBack ID = 121, Status = Transmission complete and ACK received(0) 2020-11-24 17:09:04.570 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 30: resetResendCount initComplete=true isDead=false 2020-11-24 17:09:04.573 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 1479: Advanced to WAIT_DATA 2020-11-24 17:09:04.574 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 30: TID 1479: Transaction not completed 2020-11-24 17:09:04.577 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=30, callback=0, payload=00 1E 06 85 03 02 05 00 01 2020-11-24 17:09:04.579 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2020-11-24 17:09:04.581 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 30: Application Command Request (ALIVE:DONE) 2020-11-24 17:09:04.582 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 30: resetResendCount initComplete=true isDead=false 2020-11-24 17:09:04.585 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 30: Incoming command class COMMAND_CLASS_ASSOCIATION, endpoint 0 2020-11-24 17:09:04.586 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 30: SECURITY NOT required on COMMAND_CLASS_ASSOCIATION 2020-11-24 17:09:04.588 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 30: Received COMMAND_CLASS_ASSOCIATION V2 ASSOCIATIONCMD_REPORT 2020-11-24 17:09:04.590 [DEBUG] [ndclass.ZWaveAssociationCommandClass] - NODE 30: association group 2 has max associations 5 2020-11-24 17:09:04.592 [DEBUG] [ndclass.ZWaveAssociationCommandClass] - NODE 30: association group 2 includes the following nodes: 2020-11-24 17:09:04.594 [DEBUG] [ndclass.ZWaveAssociationCommandClass] - Node 1 2020-11-24 17:09:04.596 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 30: Got an event from Z-Wave network: ZWaveAssociationEvent 2020-11-24 17:09:04.598 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 30: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_ASSOCIATION, value=0 2020-11-24 17:09:04.600 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 30: Commands processed 1. 2020-11-24 17:09:04.602 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 30: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@173e947. 2020-11-24 17:09:04.604 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 30: Command verified org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@173e947. 2020-11-24 17:09:04.606 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 30: notifyTransactionResponse TID:1479 DONE 2020-11-24 17:09:04.609 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 30: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 2020-11-24 17:09:04.610 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1 2020-11-24 17:09:04.612 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2020-11-24 17:09:04.613 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-11-24 17:09:04.615 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-11-24 17:09:09.212 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 10 00 04 00 0D 0A 60 0D 02 01 31 05 01 22 00 F0 65 2020-11-24 17:09:09.217 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=13, callback=0, payload=00 0D 0A 60 0D 02 01 31 05 01 22 00 F0 2020-11-24 17:09:09.220 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=13, callback=0, payload=00 0D 0A 60 0D 02 01 31 05 01 22 00 F0 2020-11-24 17:09:09.221 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2020-11-24 17:09:09.223 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 13: Application Command Request (ALIVE:DONE) 2020-11-24 17:09:09.224 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 13: resetResendCount initComplete=true isDead=false 2020-11-24 17:09:09.226 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 13: Decapsulating COMMAND_CLASS_MULTI_CHANNEL 2020-11-24 17:09:09.228 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 13: Incoming command class COMMAND_CLASS_SENSOR_MULTILEVEL, endpoint 2 2020-11-24 17:09:09.229 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 13: SECURITY NOT required on COMMAND_CLASS_SENSOR_MULTILEVEL 2020-11-24 17:09:09.231 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 13: Received COMMAND_CLASS_SENSOR_MULTILEVEL V0 SENSOR_MULTILEVEL_REPORT 2020-11-24 17:09:09.233 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 13: Sensor Type = Temperature(1), Scale = 0 2020-11-24 17:09:09.234 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 13: Sensor Value = 24 2020-11-24 17:09:09.236 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 13: Got an event from Z-Wave network: ZWaveMultiLevelSensorValueEvent 2020-11-24 17:09:09.238 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 10 00 04 00 0D 0A 60 0D 03 01 31 05 01 22 00 00 94 2020-11-24 17:09:09.238 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 13: Got a value event from Z-Wave network, endpoint=2, command class=COMMAND_CLASS_SENSOR_MULTILEVEL, value=24 2020-11-24 17:09:09.240 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 13: Updating channel state zwave:device:5727c0c5:node13:sensor_temperature2 to 24 °C [QuantityType] 2020-11-24 17:09:09.243 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=13, callback=0, payload=00 0D 0A 60 0D 03 01 31 05 01 22 00 00 2020-11-24 17:09:09.244 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 13: Commands processed 1. 2020-11-24 17:09:09.250 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 13: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@111b469. 2020-11-24 17:09:09.252 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2020-11-24 17:09:09.254 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2020-11-24 17:09:09.256 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=13, callback=0, payload=00 0D 0A 60 0D 03 01 31 05 01 22 00 00 2020-11-24 17:09:09.260 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2020-11-24 17:09:09.262 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 13: Application Command Request (ALIVE:DONE) 2020-11-24 17:09:09.263 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 13: resetResendCount initComplete=true isDead=false 2020-11-24 17:09:09.264 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 10 00 04 00 0D 0A 60 0D 04 01 31 05 01 22 00 00 93 2020-11-24 17:09:09.265 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 13: Decapsulating COMMAND_CLASS_MULTI_CHANNEL 2020-11-24 17:09:09.267 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 13: Incoming command class COMMAND_CLASS_SENSOR_MULTILEVEL, endpoint 3 2020-11-24 17:09:09.270 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=13, callback=0, payload=00 0D 0A 60 0D 04 01 31 05 01 22 00 00 2020-11-24 17:09:09.269 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 13: SECURITY NOT required on COMMAND_CLASS_SENSOR_MULTILEVEL 2020-11-24 17:09:09.272 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 13: Received COMMAND_CLASS_SENSOR_MULTILEVEL V0 SENSOR_MULTILEVEL_REPORT 2020-11-24 17:09:09.274 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 13: Sensor Type = Temperature(1), Scale = 0 2020-11-24 17:09:09.276 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 13: Sensor Value = 0E+1 2020-11-24 17:09:09.278 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 13: Got an event from Z-Wave network: ZWaveMultiLevelSensorValueEvent 2020-11-24 17:09:09.280 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 13: Got a value event from Z-Wave network, endpoint=3, command class=COMMAND_CLASS_SENSOR_MULTILEVEL, value=0E+1 2020-11-24 17:09:09.282 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 13: Updating channel state zwave:device:5727c0c5:node13:sensor_temperature3 to 0E+1 °C [QuantityType] 2020-11-24 17:09:09.285 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 13: Commands processed 1. 2020-11-24 17:09:09.286 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 13: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@146608e. 2020-11-24 17:09:09.288 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2020-11-24 17:09:09.289 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2020-11-24 17:09:09.292 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=13, callback=0, payload=00 0D 0A 60 0D 04 01 31 05 01 22 00 00 2020-11-24 17:09:09.293 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2020-11-24 17:09:09.295 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 13: Application Command Request (ALIVE:DONE) 2020-11-24 17:09:09.296 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 13: resetResendCount initComplete=true isDead=false 2020-11-24 17:09:09.298 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 13: Decapsulating COMMAND_CLASS_MULTI_CHANNEL 2020-11-24 17:09:09.300 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 13: Incoming command class COMMAND_CLASS_SENSOR_MULTILEVEL, endpoint 4 2020-11-24 17:09:09.302 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 13: SECURITY NOT required on COMMAND_CLASS_SENSOR_MULTILEVEL 2020-11-24 17:09:09.304 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 13: Received COMMAND_CLASS_SENSOR_MULTILEVEL V0 SENSOR_MULTILEVEL_REPORT 2020-11-24 17:09:09.305 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 13: Sensor Type = Temperature(1), Scale = 0 2020-11-24 17:09:09.307 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 13: Sensor Value = 0E+1 2020-11-24 17:09:09.309 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 13: Got an event from Z-Wave network: ZWaveMultiLevelSensorValueEvent 2020-11-24 17:09:09.311 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 13: Got a value event from Z-Wave network, endpoint=4, command class=COMMAND_CLASS_SENSOR_MULTILEVEL, value=0E+1 2020-11-24 17:09:09.313 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 13: Updating channel state zwave:device:5727c0c5:node13:sensor_temperature4 to 0E+1 °C [QuantityType] 2020-11-24 17:09:09.315 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 13: Commands processed 1. 2020-11-24 17:09:09.317 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 13: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@19f1436. 2020-11-24 17:09:09.319 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2020-11-24 17:09:09.320 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2020-11-24 17:09:09.322 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-11-24 17:09:09.323 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.