2019-06-15 14:45:44.163 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-06-15 14:46:13.077 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:16b56bde664 2019-06-15 14:46:13.081 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave inclusion process not running - nothing to do 2019-06-15 14:46:13.088 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Start zwave:serial_zstick:16b56bde664 2019-06-15 14:46:13.091 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave controller start inclusion - mode 2 2019-06-15 14:46:13.097 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added. 2019-06-15 14:46:13.100 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller start inclusion 2019-06-15 14:46:13.108 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Setting controller into INCLUSION mode, highPower:true networkWide:true. 2019-06-15 14:46:13.111 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 407 to queue - size 1 2019-06-15 14:46:13.114 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-06-15 14:46:13.118 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A C1 76 07 2019-06-15 14:46:13.122 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A C1 76 07 2019-06-15 14:46:13.126 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2019-06-15 14:46:13.129 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2019-06-15 14:46:13.129 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 407: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 118 2019-06-15 14:46:13.133 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-06-15 14:46:13.136 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-06-15 14:46:13.137 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 407: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 118 2019-06-15 14:46:13.139 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2019-06-15 14:46:13.141 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-06-15 14:46:13.143 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2019-06-15 14:46:13.144 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 76 01 00 00 C5 2019-06-15 14:46:13.152 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=118, payload=76 01 00 00 2019-06-15 14:46:13.157 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=118, payload=76 01 00 00 2019-06-15 14:46:13.161 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 407: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 118 2019-06-15 14:46:13.164 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2019-06-15 14:46:13.167 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 407: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 118 2019-06-15 14:46:13.170 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 407: (Callback 118) 2019-06-15 14:46:13.173 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match! 2019-06-15 14:46:13.176 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 407: callback 118 2019-06-15 14:46:13.180 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=118, payload=76 01 00 00 2019-06-15 14:46:13.184 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Learn ready. 2019-06-15 14:46:15.137 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 2: Device discovery completed 2019-06-15 14:46:15.199 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 2: Device discovery resolved to thingType zwave:fibaro_fgs213_00_000 2019-06-15 14:46:15.212 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 3: Device discovery completed 2019-06-15 14:46:15.237 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 3: Device discovery resolved to thingType zwave:fibaro_fgs213_00_000 2019-06-15 14:46:15.250 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 4: Device discovery completed 2019-06-15 14:46:15.259 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 4: Device discovery resolved to thingType zwave:fibaro_fgs213_00_000 2019-06-15 14:46:15.269 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 5: Device discovery completed 2019-06-15 14:46:15.274 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 5: Device discovery resolved to thingType zwave:fibaro_fgd212_03_005 2019-06-15 14:46:15.284 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 6: Device discovery completed 2019-06-15 14:46:15.286 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 6: Device discovery resolved to thingType zwave:fibaro_fgs222_00_000 2019-06-15 14:46:15.292 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 7: Device discovery completed 2019-06-15 14:46:15.297 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 7: Device discovery resolved to thingType zwave:fibaro_fgwp102_03_002 2019-06-15 14:46:15.307 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 8: Device discovery completed 2019-06-15 14:46:15.312 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 8: Device discovery resolved to thingType zwave:fibaro_fgs213_00_000 2019-06-15 14:46:15.322 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 9: Device discovery completed 2019-06-15 14:46:15.327 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 9: Device discovery could not resolve to a thingType! Manufacturer data not known. 2019-06-15 14:46:15.330 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 10: Device discovery completed 2019-06-15 14:46:15.332 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 10: Device discovery resolved to thingType zwave:fibaro_fgms001_03_002 2019-06-15 14:46:15.337 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 11: Device discovery completed 2019-06-15 14:46:15.342 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 11: Device discovery resolved to thingType zwave:fibaro_fgs213_00_000 2019-06-15 14:46:15.353 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 12: Device discovery completed 2019-06-15 14:46:15.358 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 12: Device discovery resolved to thingType zwave:fibaro_fgwp102_03_002 2019-06-15 14:46:15.368 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 13: Device discovery completed 2019-06-15 14:46:15.373 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 13: Device discovery resolved to thingType zwave:fibaro_fgd212_03_005 2019-06-15 14:46:15.383 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 14: Device discovery completed 2019-06-15 14:46:15.387 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 14: Device discovery resolved to thingType zwave:fibaro_fgd212_03_005 2019-06-15 14:46:17.595 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 76 02 00 00 C6 2019-06-15 14:46:17.599 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=2, callback=118, payload=76 02 00 00 2019-06-15 14:46:17.855 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 1B 00 4A 76 03 0F 14 04 10 01 5E 22 85 59 70 56 5A 7A 72 32 8E 71 73 98 31 25 86 B5 2019-06-15 14:46:17.862 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 1<>127 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=3, callback=118, payload=76 03 0F 14 04 10 01 5E 22 85 59 70 56 5A 7A 72 32 8E 71 73 98 31 25 86 2019-06-15 14:46:18.135 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 407: Timeout at state WAIT_REQUEST. 3 retries remaining. 2019-06-15 14:46:18.138 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 407: Transaction is current transaction, so clearing!!!!! 2019-06-15 14:46:18.145 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 407: Transaction CANCELLED 2019-06-15 14:46:18.147 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:407 CANCELLED 2019-06-15 14:46:18.149 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-06-15 14:46:18.764 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 76 05 0F 00 CE 2019-06-15 14:46:18.768 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 2<>126 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=5, callback=118, payload=76 05 0F 00 2019-06-15 14:46:21.586 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 1A 00 49 84 0F 14 04 10 01 5E 22 85 59 70 56 5A 7A 72 32 8E 71 73 98 31 25 86 46 2019-06-15 14:46:21.594 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 3<>125 : Message: class=ApplicationUpdate[73], type=Request[0], dest=15, callback=132, payload=84 0F 14 04 10 01 5E 22 85 59 70 56 5A 7A 72 32 8E 71 73 98 31 25 86 2019-06-15 14:46:40.329 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0F 00 04 00 0A 09 71 05 00 00 00 FF 07 08 00 73 2019-06-15 14:46:40.336 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 4<>124 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 09 71 05 00 00 00 FF 07 08 00 2019-06-15 14:46:43.087 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:16b56bde664 2019-06-15 14:46:43.091 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller stopping inclusion at IncludeSent 2019-06-15 14:46:43.093 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode. 2019-06-15 14:46:43.095 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 408 to queue - size 1 2019-06-15 14:46:43.097 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-06-15 14:46:43.104 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 77 C2 2019-06-15 14:46:43.107 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 77 C2 2019-06-15 14:46:43.110 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2019-06-15 14:46:43.113 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2019-06-15 14:46:43.113 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 408: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 119 2019-06-15 14:46:43.117 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 5<>123 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-06-15 14:46:43.163 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 77 06 0F 00 CC 2019-06-15 14:46:43.167 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 6<>122 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=119, payload=77 06 0F 00 2019-06-15 14:46:48.117 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 408: Timeout at state WAIT_REQUEST. 3 retries remaining. 2019-06-15 14:46:48.119 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 408: Transaction is current transaction, so clearing!!!!! 2019-06-15 14:46:48.122 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 408: Transaction CANCELLED 2019-06-15 14:46:48.124 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:408 CANCELLED 2019-06-15 14:46:48.127 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-06-15 14:46:58.120 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion timer at IncludeDone 2019-06-15 14:47:18.817 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 10 00 04 00 0A 0A 71 05 00 00 00 FF 07 00 01 08 6E 2019-06-15 14:47:18.825 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 7<>121 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 0A 71 05 00 00 00 FF 07 00 01 08 2019-06-15 14:47:40.892 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:16b56bde664 2019-06-15 14:47:40.900 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller stopping inclusion at IncludeDone 2019-06-15 14:47:40.905 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller end exclusion 2019-06-15 14:47:40.910 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWaveController include done 2019-06-15 14:47:40.915 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Start zwave:serial_zstick:16b56bde664 2019-06-15 14:47:40.920 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave controller start inclusion - mode 2 2019-06-15 14:47:40.925 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added. 2019-06-15 14:47:40.930 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller start inclusion 2019-06-15 14:47:40.935 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Setting controller into INCLUSION mode, highPower:true networkWide:true. 2019-06-15 14:47:40.939 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 409 to queue - size 1 2019-06-15 14:47:40.944 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-06-15 14:47:40.949 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A C1 78 09 2019-06-15 14:47:40.954 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A C1 78 09 2019-06-15 14:47:40.961 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2019-06-15 14:47:40.959 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2019-06-15 14:47:40.966 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 8<>120 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-06-15 14:47:40.965 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 409: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 120 2019-06-15 14:47:40.972 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 78 01 00 00 CB 2019-06-15 14:47:40.977 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 9<>119 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=120, payload=78 01 00 00 2019-06-15 14:47:42.970 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 2: Device discovery completed 2019-06-15 14:47:42.986 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 2: Device discovery resolved to thingType zwave:fibaro_fgs213_00_000 2019-06-15 14:47:43.091 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 3: Device discovery completed 2019-06-15 14:47:43.096 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 3: Device discovery resolved to thingType zwave:fibaro_fgs213_00_000 2019-06-15 14:47:43.108 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 4: Device discovery completed 2019-06-15 14:47:43.113 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 4: Device discovery resolved to thingType zwave:fibaro_fgs213_00_000 2019-06-15 14:47:43.123 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 5: Device discovery completed 2019-06-15 14:47:43.128 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 5: Device discovery resolved to thingType zwave:fibaro_fgd212_03_005 2019-06-15 14:47:43.138 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 6: Device discovery completed 2019-06-15 14:47:43.140 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 6: Device discovery resolved to thingType zwave:fibaro_fgs222_00_000 2019-06-15 14:47:43.146 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 7: Device discovery completed 2019-06-15 14:47:43.151 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 7: Device discovery resolved to thingType zwave:fibaro_fgwp102_03_002 2019-06-15 14:47:43.161 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 8: Device discovery completed 2019-06-15 14:47:43.166 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 8: Device discovery resolved to thingType zwave:fibaro_fgs213_00_000 2019-06-15 14:47:43.176 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 9: Device discovery completed 2019-06-15 14:47:43.181 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 9: Device discovery could not resolve to a thingType! Manufacturer data not known. 2019-06-15 14:47:43.184 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 10: Device discovery completed 2019-06-15 14:47:43.186 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 10: Device discovery resolved to thingType zwave:fibaro_fgms001_03_002 2019-06-15 14:47:43.191 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 11: Device discovery completed 2019-06-15 14:47:43.196 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 11: Device discovery resolved to thingType zwave:fibaro_fgs213_00_000 2019-06-15 14:47:43.207 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 12: Device discovery completed 2019-06-15 14:47:43.212 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 12: Device discovery resolved to thingType zwave:fibaro_fgwp102_03_002 2019-06-15 14:47:43.222 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 13: Device discovery completed 2019-06-15 14:47:43.226 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 13: Device discovery resolved to thingType zwave:fibaro_fgd212_03_005 2019-06-15 14:47:43.236 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 14: Device discovery completed 2019-06-15 14:47:43.240 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 14: Device discovery resolved to thingType zwave:fibaro_fgd212_03_005 2019-06-15 14:47:45.969 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 409: Timeout at state WAIT_REQUEST. 3 retries remaining. 2019-06-15 14:47:45.972 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 409: Transaction is current transaction, so clearing!!!!! 2019-06-15 14:47:45.975 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 409: Transaction CANCELLED 2019-06-15 14:47:45.978 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:409 CANCELLED 2019-06-15 14:47:45.981 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-06-15 14:47:53.071 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0F 00 04 10 0A 09 71 05 00 00 00 FF 07 08 00 63 2019-06-15 14:47:53.077 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 10<>118 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=16, payload=10 0A 09 71 05 00 00 00 FF 07 08 00 2019-06-15 14:47:53.214 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0F 00 04 10 0A 09 71 05 00 00 00 FF 07 08 00 63 2019-06-15 14:47:53.221 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 11<>117 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=16, payload=10 0A 09 71 05 00 00 00 FF 07 08 00 2019-06-15 14:47:53.269 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0F 00 04 10 0A 09 71 05 00 00 00 FF 07 08 00 63 2019-06-15 14:47:53.275 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 12<>116 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=16, payload=10 0A 09 71 05 00 00 00 FF 07 08 00 2019-06-15 14:47:53.441 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0F 00 04 10 0A 09 71 05 00 00 00 FF 07 08 00 63 2019-06-15 14:47:53.447 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 13<>115 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=16, payload=10 0A 09 71 05 00 00 00 FF 07 08 00 2019-06-15 14:47:53.720 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0F 00 04 10 0A 09 71 05 00 00 00 FF 07 08 00 63 2019-06-15 14:47:53.725 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 14<>114 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=16, payload=10 0A 09 71 05 00 00 00 FF 07 08 00 2019-06-15 14:47:55.347 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0F 00 04 10 09 09 71 05 00 00 00 FF 06 16 00 7F 2019-06-15 14:47:55.352 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 15<>113 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=9, callback=16, payload=10 09 09 71 05 00 00 00 FF 06 16 00 2019-06-15 14:47:55.482 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0F 00 04 10 09 09 71 05 00 00 00 FF 06 16 00 7F 2019-06-15 14:47:55.487 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 16<>112 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=9, callback=16, payload=10 09 09 71 05 00 00 00 FF 06 16 00 2019-06-15 14:47:55.513 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0F 00 04 10 09 09 71 05 00 00 00 FF 06 16 00 7F 2019-06-15 14:47:55.518 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 17<>111 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=9, callback=16, payload=10 09 09 71 05 00 00 00 FF 06 16 00 2019-06-15 14:47:55.712 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0F 00 04 10 09 09 71 05 00 00 00 FF 06 16 00 7F 2019-06-15 14:47:55.717 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 18<>110 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=9, callback=16, payload=10 09 09 71 05 00 00 00 FF 06 16 00 2019-06-15 14:47:55.725 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0F 00 04 10 09 09 71 05 00 00 00 FF 06 16 00 7F 2019-06-15 14:47:55.730 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 19<>109 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=9, callback=16, payload=10 09 09 71 05 00 00 00 FF 06 16 00 2019-06-15 14:48:01.209 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 1A 00 4A 78 02 09 13 04 07 01 5E 85 59 22 80 70 56 5A 7A 72 8E 71 73 31 86 84 26 2019-06-15 14:48:01.216 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 20<>108 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=2, callback=120, payload=78 02 09 13 04 07 01 5E 85 59 22 80 70 56 5A 7A 72 8E 71 73 31 86 84 2019-06-15 14:48:01.222 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 1A 00 4A 78 03 09 13 04 07 01 5E 85 59 22 80 70 56 5A 7A 72 8E 71 73 31 86 84 27 2019-06-15 14:48:01.229 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 21<>107 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=3, callback=120, payload=78 03 09 13 04 07 01 5E 85 59 22 80 70 56 5A 7A 72 8E 71 73 31 86 84 2019-06-15 14:48:01.235 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 1A 00 4A 78 05 09 13 04 07 01 5E 85 59 22 80 70 56 5A 7A 72 8E 71 73 31 86 84 21 2019-06-15 14:48:01.242 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 22<>106 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=5, callback=120, payload=78 05 09 13 04 07 01 5E 85 59 22 80 70 56 5A 7A 72 8E 71 73 31 86 84 2019-06-15 14:48:07.252 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0F 00 04 00 09 09 71 05 00 00 00 FF 06 17 00 6E 2019-06-15 14:48:07.256 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 23<>105 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=9, callback=0, payload=00 09 09 71 05 00 00 00 FF 06 17 00 2019-06-15 14:48:10.915 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:16b56bde664 2019-06-15 14:48:10.919 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller stopping inclusion at IncludeSent 2019-06-15 14:48:10.922 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode. 2019-06-15 14:48:10.925 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 410 to queue - size 1 2019-06-15 14:48:10.928 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-06-15 14:48:10.932 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 79 CC 2019-06-15 14:48:10.936 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 79 CC 2019-06-15 14:48:10.939 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2019-06-15 14:48:10.942 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2019-06-15 14:48:10.943 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 410: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 121 2019-06-15 14:48:10.951 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 24<>104 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-06-15 14:48:10.992 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 79 06 09 00 C4 2019-06-15 14:48:10.994 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 25<>103 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=121, payload=79 06 09 00 2019-06-15 14:48:15.946 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 410: Timeout at state WAIT_REQUEST. 3 retries remaining. 2019-06-15 14:48:15.947 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 410: Transaction is current transaction, so clearing!!!!! 2019-06-15 14:48:15.949 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 410: Transaction CANCELLED 2019-06-15 14:48:15.951 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:410 CANCELLED 2019-06-15 14:48:15.953 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-06-15 14:48:25.952 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion timer at IncludeDone 2019-06-15 14:48:38.101 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Polling... 2019-06-15 14:48:38.104 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Polling deferred until initialisation complete 2019-06-15 14:48:46.018 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave inclusion controller finalised 2019-06-15 14:48:47.238 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 10 00 04 00 0A 0A 71 05 00 00 00 FF 07 00 01 08 6E 2019-06-15 14:48:47.245 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 26<>102 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 0A 71 05 00 00 00 FF 07 00 01 08 2019-06-15 14:49:16.650 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 10 00 04 00 0D 0A 60 0D 01 01 31 05 04 22 00 CA 59 2019-06-15 14:49:16.656 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 27<>101 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=13, callback=0, payload=00 0D 0A 60 0D 01 01 31 05 04 22 00 CA 2019-06-15 14:49:16.717 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0D 00 04 00 0D 07 60 0D 01 01 26 03 63 D7 2019-06-15 14:49:16.722 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 28<>100 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=13, callback=0, payload=00 0D 07 60 0D 01 01 26 03 63 2019-06-15 14:49:19.497 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0D 00 04 00 0D 07 60 0D 01 01 26 03 00 B4 2019-06-15 14:49:19.502 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 29<>99 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=13, callback=0, payload=00 0D 07 60 0D 01 01 26 03 00 2019-06-15 14:49:21.012 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 10 00 04 00 0E 0A 60 0D 01 01 31 05 04 22 00 3F AF 2019-06-15 14:49:21.017 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 30<>98 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=14, callback=0, payload=00 0E 0A 60 0D 01 01 31 05 04 22 00 3F 2019-06-15 14:49:21.270 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0D 00 04 00 0E 07 60 0D 01 01 26 03 63 D4 2019-06-15 14:49:21.274 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 31<>97 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=14, callback=0, payload=00 0E 07 60 0D 01 01 26 03 63 2019-06-15 14:49:23.318 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0D 00 04 00 0E 07 60 0D 01 01 26 03 00 B7 2019-06-15 14:49:23.322 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 32<>96 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=14, callback=0, payload=00 0E 07 60 0D 01 01 26 03 00 2019-06-15 14:49:26.646 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 10 00 04 00 0D 0A 60 0D 01 01 31 05 04 22 00 00 93 2019-06-15 14:49:26.651 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 33<>95 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=13, callback=0, payload=00 0D 0A 60 0D 01 01 31 05 04 22 00 00 2019-06-15 14:49:31.002 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 10 00 04 00 0E 0A 60 0D 01 01 31 05 04 22 00 00 90 2019-06-15 14:49:31.006 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 34<>94 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=14, callback=0, payload=00 0E 0A 60 0D 01 01 31 05 04 22 00 00 2019-06-15 14:51:00.731 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 12 00 04 00 08 0C 60 0D 01 01 32 02 21 32 00 00 00 00 A3 2019-06-15 14:51:00.736 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 35<>93 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=0, payload=00 08 0C 60 0D 01 01 32 02 21 32 00 00 00 00