23:42:25.934 [DEBUG] [zwave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:16c934373e7 23:42:25.937 [DEBUG] [ave.internal.protocol.ZWaveController] - ZWave inclusion process not running - nothing to do 23:42:25.942 [DEBUG] [zwave.discovery.ZWaveDiscoveryService] - ZWave discovery: Start zwave:serial_zstick:16c934373e7 23:42:25.944 [DEBUG] [ave.internal.protocol.ZWaveController] - ZWave controller start inclusion - mode 1 23:42:25.947 [DEBUG] [ave.internal.protocol.ZWaveController] - Event listener added. 23:42:25.948 [DEBUG] [nal.protocol.ZWaveInclusionController] - ZWave controller start inclusion 23:42:25.949 [DEBUG] [col.serialmessage.AddNodeMessageClass] - Setting controller into INCLUSION mode, highPower:true networkWide:false. 23:42:25.950 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 255: Added 78 to queue - size 1 23:42:25.951 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 23:42:25.952 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 81 40 71 23:42:25.954 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 81 40 71 23:42:25.955 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT 23:42:25.956 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 23:42:25.958 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 23:42:25.959 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 23:42:25.959 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null 23:42:25.960 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK 23:42:25.960 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:25.961 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 40 01 00 00 F3 23:42:25.961 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=64, payload=40 01 00 00 23:42:25.959 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 78: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 64 23:42:25.964 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:42:25.965 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=64, payload=40 01 00 00 23:42:25.966 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 78: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 64 23:42:25.966 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 23:42:25.966 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 78: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 64 23:42:25.967 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking TID 78: (Callback 64) 23:42:25.968 [DEBUG] [l.serialmessage.ZWaveCommandProcessor] - Callback match! 23:42:25.968 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Correlated to TID 78: callback 64 23:42:25.969 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=64, payload=40 01 00 00 23:42:25.970 [DEBUG] [col.serialmessage.AddNodeMessageClass] - Add Node: Learn ready. 23:42:25.971 [DEBUG] [nal.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeSent, new event IncludeStart 23:42:25.972 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 78: Transaction COMPLETED 23:42:25.972 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 13ms 23:42:25.973 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 255: TID 78: Transaction completed 23:42:25.974 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:78 DONE 23:42:25.975 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:25.975 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 23:42:27.981 [DEBUG] [zwave.discovery.ZWaveDiscoveryService] - NODE 5: Device discovery completed 23:42:27.982 [DEBUG] [zwave.discovery.ZWaveDiscoveryService] - NODE 5: Device discovery resolved to thingType zwave:homeseer_hsds100_00_000 23:42:27.983 [DEBUG] [zwave.discovery.ZWaveDiscoveryService] - NODE 6: Device discovery completed 23:42:27.984 [DEBUG] [zwave.discovery.ZWaveDiscoveryService] - NODE 6: Device discovery resolved to thingType zwave:aeotec_zwa005_00_000 23:42:27.985 [DEBUG] [zwave.discovery.ZWaveDiscoveryService] - NODE 7: Device discovery completed 23:42:27.986 [DEBUG] [zwave.discovery.ZWaveDiscoveryService] - NODE 7: Device discovery resolved to thingType zwave:homeseer_hsds100_00_000 23:42:27.986 [DEBUG] [zwave.discovery.ZWaveDiscoveryService] - NODE 8: Device discovery completed 23:42:27.987 [DEBUG] [zwave.discovery.ZWaveDiscoveryService] - NODE 8: Device discovery resolved to thingType zwave:aeotec_zw164_00_000 23:42:27.988 [DEBUG] [zwave.discovery.ZWaveDiscoveryService] - NODE 12: Device discovery completed 23:42:27.989 [DEBUG] [zwave.discovery.ZWaveDiscoveryService] - NODE 12: Device discovery resolved to thingType zwave:homeseer_hsds100_00_000 23:42:30.430 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 40 02 00 00 F0 23:42:30.433 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=2, callback=64, payload=40 02 00 00 23:42:30.434 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=2, callback=64, payload=40 02 00 00 23:42:30.434 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null 23:42:30.434 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 0 23:42:30.435 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: null 23:42:30.435 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=2, callback=64, payload=40 02 00 00 23:42:30.435 [DEBUG] [col.serialmessage.AddNodeMessageClass] - Add Node: New node found. 23:42:30.435 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:30.436 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 23:42:30.659 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 1D 00 4A 40 03 11 16 04 07 01 5E 98 9F 55 86 73 85 8E 59 72 5A 80 84 30 71 31 70 6C 7A 7F 23:42:30.662 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=3, callback=64, payload=40 03 11 16 04 07 01 5E 98 9F 55 86 73 85 8E 5 9 72 5A 80 84 30 71 31 70 6C 7A 23:42:30.665 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=3, callback=64, payload=40 03 11 16 04 07 01 5E 98 9F 55 86 73 85 8E 59 72 5A 80 84 30 71 31 70 6C 7A 23:42:30.667 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null 23:42:30.668 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 0 23:42:30.669 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: null 23:42:30.670 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=3, callback=64, payload=40 03 11 16 04 07 01 5E 98 9F 55 86 73 85 8E 59 72 5A 80 84 30 71 31 70 6C 7A 23:42:30.683 [DEBUG] [col.serialmessage.AddNodeMessageClass] - NODE 17: Adding slave. 23:42:30.684 [DEBUG] [nal.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeStart, new event IncludeSlaveFound 23:42:30.685 [DEBUG] [nal.protocol.ZWaveInclusionController] - NODE 17: Including node. 23:42:30.686 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:30.687 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 23:42:31.063 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 40 05 11 00 E6 23:42:31.067 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=5, callback=64, payload=40 05 11 00 23:42:31.068 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=5, callback=64, payload=40 05 11 00 23:42:31.069 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null 23:42:31.069 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 0 23:42:31.069 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: null 23:42:31.070 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=5, callback=64, payload=40 05 11 00 23:42:31.070 [DEBUG] [col.serialmessage.AddNodeMessageClass] - NODE 17: Add Node: Protocol done. 23:42:31.071 [DEBUG] [nal.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeSlaveFound, new event IncludeProtocolDone 23:42:31.071 [DEBUG] [col.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode. 23:42:31.072 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 255: Added 79 to queue - size 1 23:42:31.072 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 23:42:31.073 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 41 F4 23:42:31.073 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 41 F4 23:42:31.074 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT 23:42:31.074 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 79: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 65 23:42:31.074 [DEBUG] [nal.protocol.ZWaveInclusionController] - NODE 17: Inclusion protocol completed. 23:42:31.075 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Creating new instance of command class COMMAND_CLASS_NO_OPERATION 23:42:31.075 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Command class COMMAND_CLASS_NO_OPERATION, endpoint 0 created 23:42:31.076 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Version = 1, version set. Enabling extra functionality. 23:42:31.076 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Adding command class COMMAND_CLASS_NO_OPERATION to the list of supported command classes. 23:42:31.077 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Creating new instance of command class COMMAND_CLASS_BASIC 23:42:31.077 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Command class COMMAND_CLASS_BASIC, endpoint 0 created 23:42:31.078 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Adding command class COMMAND_CLASS_BASIC to the list of supported command classes. 23:42:31.078 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Creating new instance of command class COMMAND_CLASS_ZWAVEPLUS_INFO 23:42:31.079 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Command class COMMAND_CLASS_ZWAVEPLUS_INFO, endpoint 0 created 23:42:31.079 [DEBUG] [nal.protocol.ZWaveInclusionController] - NODE 17: Inclusion is adding command class COMMAND_CLASS_ZWAVEPLUS_INFO. 23:42:31.080 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Adding command class COMMAND_CLASS_ZWAVEPLUS_INFO to the list of supported command classes. 23:42:31.080 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Creating new instance of command class COMMAND_CLASS_SECURITY 23:42:31.080 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Command class COMMAND_CLASS_SECURITY, endpoint 0 created 23:42:31.081 [DEBUG] [nal.protocol.ZWaveInclusionController] - NODE 17: Inclusion is adding command class COMMAND_CLASS_SECURITY. 23:42:31.081 [DEBUG] [ommandclass.ZWaveSecurityCommandClass] - NODE 17: Updated networkKey 23:42:31.082 [DEBUG] [ommandclass.ZWaveSecurityCommandClass] - NODE 17: setupNetworkKey useSchemeZero=false 23:42:31.082 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Adding command class COMMAND_CLASS_SECURITY to the list of supported command classes. 23:42:31.083 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Creating new instance of command class COMMAND_CLASS_SECURITY 23:42:31.083 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Command class COMMAND_CLASS_SECURITY, endpoint 0 created 23:42:31.084 [DEBUG] [nal.protocol.ZWaveInclusionController] - NODE 17: Inclusion is adding command class COMMAND_CLASS_SECURITY_2. 23:42:31.084 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Adding command class COMMAND_CLASS_SECURITY to the list of supported command classes. 23:42:31.085 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Unsupported command class COMMAND_CLASS_TRANSPORT_SERVICE 23:42:31.085 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Creating new instance of command class COMMAND_CLASS_VERSION 23:42:31.086 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Command class COMMAND_CLASS_VERSION, endpoint 0 created 23:42:31.086 [DEBUG] [nal.protocol.ZWaveInclusionController] - NODE 17: Inclusion is adding command class COMMAND_CLASS_VERSION. 23:42:31.086 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Adding command class COMMAND_CLASS_VERSION to the list of supported command classes. 23:42:31.087 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Creating new instance of command class COMMAND_CLASS_POWERLEVEL 23:42:31.087 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Command class COMMAND_CLASS_POWERLEVEL, endpoint 0 created 23:42:31.088 [DEBUG] [nal.protocol.ZWaveInclusionController] - NODE 17: Inclusion is adding command class COMMAND_CLASS_POWERLEVEL. 23:42:31.088 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Adding command class COMMAND_CLASS_POWERLEVEL to the list of supported command classes. 23:42:31.089 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Creating new instance of command class COMMAND_CLASS_ASSOCIATION 23:42:31.089 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Command class COMMAND_CLASS_ASSOCIATION, endpoint 0 created 23:42:31.090 [DEBUG] [nal.protocol.ZWaveInclusionController] - NODE 17: Inclusion is adding command class COMMAND_CLASS_ASSOCIATION. 23:42:31.090 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Adding command class COMMAND_CLASS_ASSOCIATION to the list of supported command classes. 23:42:31.090 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Creating new instance of command class COMMAND_CLASS_MULTI_CHANNEL_ASSOCIATION 23:42:31.091 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Command class COMMAND_CLASS_MULTI_CHANNEL_ASSOCIATION, endpoint 0 created 23:42:31.091 [DEBUG] [nal.protocol.ZWaveInclusionController] - NODE 17: Inclusion is adding command class COMMAND_CLASS_MULTI_CHANNEL_ASSOCIATION. 23:42:31.092 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Adding command class COMMAND_CLASS_MULTI_CHANNEL_ASSOCIATION to the list of supported command classes. 23:42:31.092 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Creating new instance of command class COMMAND_CLASS_ASSOCIATION_GRP_INFO 23:42:31.092 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Command class COMMAND_CLASS_ASSOCIATION_GRP_INFO, endpoint 0 created 23:42:31.093 [DEBUG] [nal.protocol.ZWaveInclusionController] - NODE 17: Inclusion is adding command class COMMAND_CLASS_ASSOCIATION_GRP_INFO. 23:42:31.093 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Adding command class COMMAND_CLASS_ASSOCIATION_GRP_INFO to the list of supported command classes. 23:42:31.093 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Creating new instance of command class COMMAND_CLASS_MANUFACTURER_SPECIFIC 23:42:31.094 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Command class COMMAND_CLASS_MANUFACTURER_SPECIFIC, endpoint 0 created 23:42:31.094 [DEBUG] [nal.protocol.ZWaveInclusionController] - NODE 17: Inclusion is adding command class COMMAND_CLASS_MANUFACTURER_SPECIFIC. 23:42:31.095 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Adding command class COMMAND_CLASS_MANUFACTURER_SPECIFIC to the list of supported command classes. 23:42:31.095 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Creating new instance of command class COMMAND_CLASS_DEVICE_RESET_LOCALLY 23:42:31.096 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Command class COMMAND_CLASS_DEVICE_RESET_LOCALLY, endpoint 0 created 23:42:31.104 [DEBUG] [nal.protocol.ZWaveInclusionController] - NODE 17: Inclusion is adding command class COMMAND_CLASS_DEVICE_RESET_LOCALLY. 23:42:31.104 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Adding command class COMMAND_CLASS_DEVICE_RESET_LOCALLY to the list of supported command classes. 23:42:31.105 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Creating new instance of command class COMMAND_CLASS_BATTERY 23:42:31.105 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Command class COMMAND_CLASS_BATTERY, endpoint 0 created 23:42:31.112 [DEBUG] [nal.protocol.ZWaveInclusionController] - NODE 17: Inclusion is adding command class COMMAND_CLASS_BATTERY. 23:42:31.112 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Adding command class COMMAND_CLASS_BATTERY to the list of supported command classes. 23:42:31.113 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Creating new instance of command class COMMAND_CLASS_WAKE_UP 23:42:31.114 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Command class COMMAND_CLASS_WAKE_UP, endpoint 0 created 23:42:31.115 [DEBUG] [nal.protocol.ZWaveInclusionController] - NODE 17: Inclusion is adding command class COMMAND_CLASS_WAKE_UP. 23:42:31.115 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Adding command class COMMAND_CLASS_WAKE_UP to the list of supported command classes. 23:42:31.117 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Creating new instance of command class COMMAND_CLASS_SENSOR_BINARY 23:42:31.117 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Command class COMMAND_CLASS_SENSOR_BINARY, endpoint 0 created 23:42:31.118 [DEBUG] [nal.protocol.ZWaveInclusionController] - NODE 17: Inclusion is adding command class COMMAND_CLASS_SENSOR_BINARY. 23:42:31.119 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Adding command class COMMAND_CLASS_SENSOR_BINARY to the list of supported command classes. 23:42:31.120 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Creating new instance of command class COMMAND_CLASS_ALARM 23:42:31.121 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Command class COMMAND_CLASS_ALARM, endpoint 0 created 23:42:31.122 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 23:42:31.123 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 23:42:31.122 [DEBUG] [nal.protocol.ZWaveInclusionController] - NODE 17: Inclusion is adding command class COMMAND_CLASS_ALARM. 23:42:31.124 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Adding command class COMMAND_CLASS_ALARM to the list of supported command classes. 23:42:31.125 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Creating new instance of command class COMMAND_CLASS_SENSOR_MULTILEVEL 23:42:31.125 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Command class COMMAND_CLASS_SENSOR_MULTILEVEL, endpoint 0 created 23:42:31.126 [DEBUG] [nal.protocol.ZWaveInclusionController] - NODE 17: Inclusion is adding command class COMMAND_CLASS_SENSOR_MULTILEVEL. 23:42:31.126 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Adding command class COMMAND_CLASS_SENSOR_MULTILEVEL to the list of supported command classes. 23:42:31.127 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Creating new instance of command class COMMAND_CLASS_CONFIGURATION 23:42:31.127 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Command class COMMAND_CLASS_CONFIGURATION, endpoint 0 created 23:42:31.128 [DEBUG] [nal.protocol.ZWaveInclusionController] - NODE 17: Inclusion is adding command class COMMAND_CLASS_CONFIGURATION. 23:42:31.129 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Adding command class COMMAND_CLASS_CONFIGURATION to the list of supported command classes. 23:42:31.129 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Unsupported command class COMMAND_CLASS_SUPERVISION 23:42:31.130 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Creating new instance of command class COMMAND_CLASS_FIRMWARE_UPDATE_MD 23:42:31.131 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Command class COMMAND_CLASS_FIRMWARE_UPDATE_MD, endpoint 0 created 23:42:31.131 [DEBUG] [nal.protocol.ZWaveInclusionController] - NODE 17: Inclusion is adding command class COMMAND_CLASS_FIRMWARE_UPDATE_MD. 23:42:31.132 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Adding command class COMMAND_CLASS_FIRMWARE_UPDATE_MD to the list of supported command classes. 23:42:31.133 [DEBUG] [ave.internal.protocol.ZWaveController] - NODE 17: ZWaveController include node 23:42:31.133 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 17: Starting initialisation from INCLUSION_START 23:42:31.136 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 23:42:31.136 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 79: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 65 23:42:31.137 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK 23:42:31.138 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:31.138 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:42:31.139 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 17: Node advancer: Node just included (6211442) 23:42:31.139 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 17: Node advancer - advancing to IDENTIFY_NODE 23:42:31.140 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 17: Node advancer: Initialisation starting from inclusion 23:42:31.141 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 255: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@2316360a 23:42:31.144 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 255: Added 80 to queue - size 1 23:42:31.145 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:42:31.173 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 41 06 11 00 E4 23:42:31.173 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=65, payload=41 06 11 00 23:42:31.174 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=65, payload=41 06 11 00 23:42:31.174 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 79: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 65 23:42:31.174 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 23:42:31.174 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 79: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 65 23:42:31.175 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking TID 79: (Callback 65) 23:42:31.175 [DEBUG] [l.serialmessage.ZWaveCommandProcessor] - Callback match! 23:42:31.175 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Correlated to TID 79: callback 65 23:42:31.175 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=65, payload=41 06 11 00 23:42:31.175 [DEBUG] [col.serialmessage.AddNodeMessageClass] - Add Node: Done. 23:42:31.176 [DEBUG] [zwave.discovery.ZWaveDiscoveryService] - NODE 17: Device discovered 23:42:31.176 [INFO ] [ig.discovery.internal.PersistentInbox] - Added new thing 'zwave:device:16c934373e7:node17' to inbox. 23:42:31.177 [DEBUG] [nal.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeProtocolDone, new event IncludeDone 23:42:31.177 [DEBUG] [col.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode. 23:42:31.177 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 255: Added 81 to queue - size 2 23:42:31.177 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:42:31.177 [DEBUG] [nal.protocol.ZWaveInclusionController] - ZWave controller end exclusion 23:42:31.178 [DEBUG] [ave.internal.protocol.ZWaveController] - ZWaveController include done 23:42:31.178 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 79: Advanced to DONE 23:42:31.178 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 104ms 23:42:31.178 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 255: TID 79: Transaction completed 23:42:31.178 [INFO ] [smarthome.event.InboxAddedEvent ] - Discovery Result with UID 'zwave:device:16c934373e7:node17' has been added. 23:42:31.178 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:79 DONE 23:42:31.179 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:31.179 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 23:42:31.180 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 00 41 11 AB 23:42:31.180 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 04 00 41 11 AB 23:42:31.180 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT 23:42:31.181 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 80: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 23:42:31.228 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 23:42:31.229 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 23:42:31.230 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 23:42:31.230 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 80: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 23:42:31.231 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK 23:42:31.231 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:31.232 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:42:31.273 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 01 41 53 9C 01 04 07 01 7A 23:42:31.273 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=53 9C 01 04 07 01 23:42:31.274 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=53 9C 01 04 07 01 23:42:31.275 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 80: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 23:42:31.275 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 23:42:31.275 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 80: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 23:42:31.275 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=53 9C 01 04 07 01 23:42:31.276 [DEBUG] [erialmessage.IdentifyNodeMessageClass] - NODE 17: ProtocolInfo 23:42:31.276 [DEBUG] [erialmessage.IdentifyNodeMessageClass] - NODE 17: Listening = false 23:42:31.276 [DEBUG] [erialmessage.IdentifyNodeMessageClass] - NODE 17: Routing = true 23:42:31.276 [DEBUG] [erialmessage.IdentifyNodeMessageClass] - NODE 17: Beaming = true 23:42:31.277 [DEBUG] [erialmessage.IdentifyNodeMessageClass] - NODE 17: Version = 4 23:42:31.277 [DEBUG] [erialmessage.IdentifyNodeMessageClass] - NODE 17: FLIRS = false 23:42:31.277 [DEBUG] [erialmessage.IdentifyNodeMessageClass] - NODE 17: Security = false 23:42:31.277 [DEBUG] [erialmessage.IdentifyNodeMessageClass] - NODE 17: Max Baud = 40000 23:42:31.277 [DEBUG] [erialmessage.IdentifyNodeMessageClass] - NODE 17: Basic = BASIC_TYPE_ROUTING_SLAVE 23:42:31.278 [DEBUG] [erialmessage.IdentifyNodeMessageClass] - NODE 17: Generic = GENERIC_TYPE_SENSOR_NOTIFICATION 23:42:31.278 [DEBUG] [erialmessage.IdentifyNodeMessageClass] - NODE 17: Specific = SPECIFIC_TYPE_NOTIFICATION_SENSOR 23:42:31.278 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Creating new instance of command class COMMAND_CLASS_NO_OPERATION 23:42:31.278 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Command class COMMAND_CLASS_NO_OPERATION, endpoint 0 created 23:42:31.279 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Version = 1, version set. Enabling extra functionality. 23:42:31.279 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Adding command class COMMAND_CLASS_NO_OPERATION to the list of supported command classes. 23:42:31.279 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Creating new instance of command class COMMAND_CLASS_BASIC 23:42:31.279 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Command class COMMAND_CLASS_BASIC, endpoint 0 created 23:42:31.279 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Adding command class COMMAND_CLASS_BASIC to the list of supported command classes. 23:42:31.280 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 80: Transaction COMPLETED 23:42:31.280 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 99ms 23:42:31.280 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 255: TID 80: Transaction completed 23:42:31.281 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:80 DONE 23:42:31.281 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:31.281 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 23:42:31.281 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 00 B5 23:42:31.282 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 00 B5 23:42:31.282 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT 23:42:31.282 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 81: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 0 23:42:31.283 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 80: Transaction event listener: DONE: DONE -> 23:42:31.283 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 17: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@29ee5d7a 23:42:31.288 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 17: Node Init transaction completed with response COMPLETE 23:42:31.344 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 23:42:31.344 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 23:42:31.345 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 23:42:31.345 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 81: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 0 23:42:31.345 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK 23:42:31.345 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:31.346 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:42:32.306 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:42:32.310 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Is awake with 0 messages in the queue 23:42:32.312 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Start sleep timer at 5000ms 23:42:32.312 [DEBUG] [ave.internal.protocol.ZWaveController] - NODE 17: Node Status event - Node is AWAKE 23:42:32.313 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 17: Node advancer - advancing to SECURITY_REPORT 23:42:32.313 [DEBUG] [ommandclass.ZWaveSecurityCommandClass] - NODE 17: Updated networkKey 23:42:32.314 [DEBUG] [ommandclass.ZWaveSecurityCommandClass] - NODE 17: setupNetworkKey useSchemeZero=false 23:42:32.314 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 17: Performing secure inclusion. 23:42:32.315 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 17: SECURITY_INC State=GET_SCHEME 23:42:32.315 [DEBUG] [mandclass.impl.CommandClassSecurityV1] - Creating command message SECURITY_SCHEME_GET version 1 23:42:32.315 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 17: ZWaveCommandClassTransactionPayload - send to node 23:42:32.315 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: SECURITY check internal 23:42:32.316 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Command Class COMMAND_CLASS_SECURITY is NOT required to be secured 23:42:32.316 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@6cecd623 23:42:32.316 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Bump transaction 82 priority from Immediate to Immediate 23:42:32.317 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Adding to device queue 23:42:32.317 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Added 82 to queue - size 2 23:42:32.317 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:42:34.813 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: WakeupTimerTask 1 Messages waiting, state SECURITY_REPORT 23:42:36.284 [DEBUG] [nsactionManager$ZWaveTransactionTimer] - NODE 255: TID 81: Timeout at state WAIT_REQUEST. 3 retries remaining. 23:42:36.289 [DEBUG] [nsactionManager$ZWaveTransactionTimer] - TID 81: Transaction is current transaction, so clearing!!!!! 23:42:36.291 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 81: Transaction CANCELLED 23:42:36.293 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:81 CANCELLED 23:42:36.295 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 23:42:36.296 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 11 03 98 04 00 25 43 0E 23:42:36.296 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 17: Sending REQUEST Message = 01 0A 00 13 11 03 98 04 00 25 43 0E 23:42:36.297 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT 23:42:36.297 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 82: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 67 23:42:36.299 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 23:42:36.299 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 23:42:36.300 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 23:42:36.300 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 82: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 67 23:42:36.300 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK 23:42:36.301 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:36.301 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:42:36.309 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 23:42:36.310 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 23:42:36.310 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 23:42:36.310 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 82: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 67 23:42:36.310 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 23:42:36.310 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 82: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 67 23:42:36.311 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 23:42:36.311 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 17: sentData successfully placed on stack. 23:42:36.311 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 82: Advanced to WAIT_REQUEST 23:42:36.311 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: TID 82: Transaction not completed 23:42:36.311 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:36.311 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:42:36.387 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 43 00 00 03 AB 23:42:36.387 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=67, payload=43 00 00 03 23:42:36.388 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=67, payload=43 00 00 03 23:42:36.388 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 82: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 67 23:42:36.388 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 23:42:36.389 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 82: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 67 23:42:36.390 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking TID 82: (Callback 67) 23:42:36.390 [DEBUG] [l.serialmessage.ZWaveCommandProcessor] - Callback match! 23:42:36.390 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Correlated to TID 82: callback 67 23:42:36.390 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=67, payload=43 00 00 03 23:42:36.391 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 17: SendData Request. CallBack ID = 67, Status = Transmission complete and ACK received(0) 23:42:36.391 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 82: Advanced to WAIT_DATA 23:42:36.391 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: TID 82: Transaction not completed 23:42:36.392 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:36.392 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:42:36.431 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 11 03 98 05 00 7D 23:42:36.432 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=17, callback=0, payload=00 11 03 98 05 00 23:42:36.433 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=17, callback=0, payload=00 11 03 98 05 00 23:42:36.434 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null 23:42:36.434 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Application Command Request (ALIVE:SECURITY_REPORT) 23:42:36.434 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Incoming command class COMMAND_CLASS_SECURITY, endpoint 0 23:42:36.435 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: SECURITY check internal 23:42:36.435 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Received COMMAND_CLASS_SECURITY V0 SECURITY_SCHEME_REPORT 23:42:36.436 [DEBUG] [ommandclass.ZWaveSecurityCommandClass] - NODE 17: setupNetworkKey useSchemeZero=true 23:42:36.437 [INFO ] [ommandclass.ZWaveSecurityCommandClass] - NODE 17: Using Scheme0 Network Key for Key Exchange since we are in inclusion mode. 23:42:36.438 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Commands processed 1. 23:42:36.438 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@51f17235. 23:42:36.439 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Command verified org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@51f17235. 23:42:36.439 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: notifyTransactionResponse TID:82 DONE 23:42:36.440 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1 23:42:36.440 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 23:42:36.440 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:36.441 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 23:42:36.443 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 82: Transaction event listener: DONE: DONE -> 23:42:36.444 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 17: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@7e581bd2 23:42:36.444 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 17: Node Init transaction completed with response COMPLETE 23:42:36.445 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 17: SECURITY_INC State=SET_KEY 23:42:36.445 [DEBUG] [mandclass.impl.CommandClassSecurityV1] - Creating command message NETWORK_KEY_SET version 1 23:42:36.445 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 17: ZWaveCommandClassTransactionPayload - send to node 23:42:36.446 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: SECURITY check internal 23:42:36.446 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Command Class COMMAND_CLASS_SECURITY is NOT required to be secured 23:42:36.446 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@5dca391d 23:42:36.447 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Bump transaction 83 priority from Immediate to Immediate 23:42:36.447 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Adding to device queue 23:42:36.448 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Added 83 to queue - size 2 23:42:36.448 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 23:42:36.448 [DEBUG] [ommandclass.ZWaveSecurityCommandClass] - NODE 17: isNonceAvailable = null 23:42:36.449 [DEBUG] [mandclass.impl.CommandClassSecurityV1] - Creating command message SECURITY_NONCE_GET version 1 23:42:36.449 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 11 02 98 40 25 44 4F 23:42:36.449 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 17: Sending REQUEST Message = 01 09 00 13 11 02 98 40 25 44 4F 23:42:36.450 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT 23:42:36.450 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 84: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 68 23:42:36.486 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 23:42:36.486 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 23:42:36.487 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 23:42:36.487 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 84: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 68 23:42:36.488 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK 23:42:36.488 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:36.488 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:42:36.527 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 23:42:36.528 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 23:42:36.528 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 23:42:36.529 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 84: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 68 23:42:36.529 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 23:42:36.529 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 84: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 68 23:42:36.530 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 23:42:36.530 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 17: sentData successfully placed on stack. 23:42:36.530 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 84: Advanced to WAIT_REQUEST 23:42:36.530 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: TID 84: Transaction not completed 23:42:36.530 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:36.530 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:42:36.571 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 44 00 00 02 AD 23:42:36.571 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=68, payload=44 00 00 02 23:42:36.572 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=68, payload=44 00 00 02 23:42:36.573 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 84: [WAIT_REQUEST] priority=High, requiresResponse=true, callback: 68 23:42:36.573 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 23:42:36.574 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 84: [WAIT_REQUEST] priority=High, requiresResponse=true, callback: 68 23:42:36.574 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking TID 84: (Callback 68) 23:42:36.574 [DEBUG] [l.serialmessage.ZWaveCommandProcessor] - Callback match! 23:42:36.575 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Correlated to TID 84: callback 68 23:42:36.575 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=68, payload=44 00 00 02 23:42:36.575 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 17: SendData Request. CallBack ID = 68, Status = Transmission complete and ACK received(0) 23:42:36.576 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 84: Advanced to WAIT_DATA 23:42:36.576 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: TID 84: Transaction not completed 23:42:36.576 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:36.577 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:42:36.615 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 10 00 04 00 11 0A 98 80 1F 90 42 49 5E 35 99 F8 66 23:42:36.615 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=17, callback=0, payload=00 11 0A 98 80 1F 90 42 49 5E 35 99 F8 23:42:36.616 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=17, callback=0, payload=00 11 0A 98 80 1F 90 42 49 5E 35 99 F8 23:42:36.616 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null 23:42:36.617 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Application Command Request (ALIVE:SECURITY_REPORT) 23:42:36.617 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Incoming command class COMMAND_CLASS_SECURITY, endpoint 0 23:42:36.618 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: SECURITY check internal 23:42:36.618 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Received COMMAND_CLASS_SECURITY V0 SECURITY_NONCE_REPORT 23:42:36.618 [DEBUG] [ommandclass.ZWaveSecurityCommandClass] - NODE 17: NONCE Received start... 23:42:36.619 [DEBUG] [ommandclass.ZWaveSecurityCommandClass] - NODE 17: NONCE Received start null 23:42:36.619 [DEBUG] [ommandclass.ZWaveSecurityCommandClass] - NODE 17: NONCE Received ZWaveNonce [nonceBytes=(1F 90 42 49 5E 35 99 F8 ), timer=101149, valid=true] 23:42:36.620 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Commands processed 1. 23:42:36.620 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@3baa098d. 23:42:36.621 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Command verified org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@3baa098d. 23:42:36.621 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: notifyTransactionResponse TID:84 DONE 23:42:36.622 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1 23:42:36.622 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 23:42:36.622 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:36.622 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 23:42:36.623 [DEBUG] [mandclass.impl.CommandClassSecurityV1] - Creating command message SECURITY_MESSAGE_ENCAPSULATION version 1 23:42:36.623 [DEBUG] [ommandclass.ZWaveSecurityCommandClass] - NODE 17: SECURITY_TXD 98 06 F4 C4 47 29 D1 32 C8 69 7F 22 11 16 F5 4A 76 E9 23:42:36.624 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 2D 00 13 11 26 98 81 68 65 62 35 28 BA 1D 0A 4B BA 69 72 2B 98 D5 47 B4 5C 6D 1A 67 CB 39 3D 7D E5 8B 1F 86 70 FC A5 63 37 3A F9 25 45 9 8 23:42:36.624 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 17: Sending REQUEST Message = 01 2D 00 13 11 26 98 81 68 65 62 35 28 BA 1D 0A 4B BA 69 72 2B 98 D5 47 B4 5C 6D 1A 67 CB 39 3D 7D E5 8B 1F 86 70 FC A5 63 37 3A F9 25 45 98 23:42:36.625 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT 23:42:36.625 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 83: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 69 23:42:36.674 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 23:42:36.674 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 23:42:36.675 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 23:42:36.675 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 83: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 69 23:42:36.675 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK 23:42:36.675 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:36.676 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:42:36.715 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 23:42:36.716 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 23:42:36.716 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 23:42:36.718 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 83: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 69 23:42:36.718 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 23:42:36.718 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 83: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 69 23:42:36.719 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 23:42:36.719 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 17: sentData successfully placed on stack. 23:42:36.720 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 83: Advanced to WAIT_REQUEST 23:42:36.720 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: TID 83: Transaction not completed 23:42:36.721 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:36.721 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:42:36.760 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 45 00 00 02 AC 23:42:36.761 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=69, payload=45 00 00 02 23:42:36.764 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=69, payload=45 00 00 02 23:42:36.768 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 83: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 69 23:42:36.770 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 23:42:36.771 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 83: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 69 23:42:36.774 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking TID 83: (Callback 69) 23:42:36.775 [DEBUG] [l.serialmessage.ZWaveCommandProcessor] - Callback match! 23:42:36.776 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Correlated to TID 83: callback 69 23:42:36.777 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=69, payload=45 00 00 02 23:42:36.780 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 17: SendData Request. CallBack ID = 69, Status = Transmission complete and ACK received(0) 23:42:36.781 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 83: Advanced to WAIT_DATA 23:42:36.782 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: TID 83: Transaction not completed 23:42:36.782 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:36.783 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:42:36.807 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 04 00 11 02 98 40 38 23:42:36.807 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=17, callback=0, payload=00 11 02 98 40 23:42:36.808 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=17, callback=0, payload=00 11 02 98 40 23:42:36.809 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null 23:42:36.811 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Application Command Request (ALIVE:SECURITY_REPORT) 23:42:36.811 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Incoming command class COMMAND_CLASS_SECURITY, endpoint 0 23:42:36.812 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: SECURITY check internal 23:42:36.814 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Received COMMAND_CLASS_SECURITY V0 SECURITY_NONCE_GET 23:42:36.815 [DEBUG] [mandclass.impl.CommandClassSecurityV1] - Creating command message SECURITY_NONCE_REPORT version 1 23:42:36.816 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Added to secure queue - size 1 23:42:36.817 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Commands processed 1. 23:42:36.818 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@16aad4f8. 23:42:36.819 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Command NOT verified org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@16aad4f8. 23:42:36.821 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1 23:42:36.822 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1 23:42:36.823 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:36.824 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:42:36.825 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 11 00 13 11 0A 98 80 F6 6D A5 EC BE 85 9F DD 25 46 36 23:42:36.826 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 17: Sending REQUEST Message = 01 11 00 13 11 0A 98 80 F6 6D A5 EC BE 85 9F DD 25 46 36 23:42:36.827 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT 23:42:36.828 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 85: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 70 23:42:36.859 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 23:42:36.859 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 23:42:36.860 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 23:42:36.860 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 85: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 70 23:42:36.861 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK 23:42:36.861 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:36.861 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 2 out at start. Holdoff false. 23:42:36.903 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 23:42:36.904 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 23:42:36.905 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 23:42:36.905 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 85: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 70 23:42:36.908 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 2 23:42:36.909 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 85: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 70 23:42:36.910 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 23:42:36.912 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 17: sentData successfully placed on stack. 23:42:36.913 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 85: Advanced to WAIT_REQUEST 23:42:36.914 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: TID 85: Transaction not completed 23:42:36.916 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:36.916 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 2 out at start. Holdoff false. 23:42:36.952 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 46 00 00 03 AE 23:42:36.953 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=70, payload=46 00 00 03 23:42:36.956 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=70, payload=46 00 00 03 23:42:36.958 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 85: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 70 23:42:36.959 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 2 23:42:36.960 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 85: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 70 23:42:36.961 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking TID 83: (Callback 69) 23:42:36.962 [DEBUG] [l.serialmessage.ZWaveCommandProcessor] - NO callback match! (69 <> 70) 23:42:36.972 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking TID 85: (Callback 70) 23:42:36.974 [DEBUG] [l.serialmessage.ZWaveCommandProcessor] - Callback match! 23:42:36.983 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Correlated to TID 85: callback 70 23:42:36.984 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=70, payload=46 00 00 03 23:42:36.985 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 17: SendData Request. CallBack ID = 70, Status = Transmission complete and ACK received(0) 23:42:36.986 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 85: Transaction COMPLETED 23:42:36.987 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Response processed after 159ms 23:42:36.987 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: TID 85: Transaction completed 23:42:36.988 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: notifyTransactionResponse TID:85 DONE 23:42:36.998 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:36.999 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:42:36.999 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 1C 00 04 00 11 16 98 81 B9 A5 C6 5B C3 4A 9A A4 33 02 3C F6 B8 EA 74 30 55 7C 51 0F 55 23:42:37.000 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=17, callback=0, payload=00 11 16 98 81 B9 A5 C6 5B C3 4A 9A A4 33 02 3C F6 B8 EA 74 30 55 7C 51 0F 23:42:37.000 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=17, callback=0, payload=00 11 16 98 81 B9 A5 C6 5B C3 4A 9A A4 33 02 3C F6 B8 EA 74 30 55 7C 51 0F 23:42:37.001 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null 23:42:37.001 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Application Command Request (ALIVE:SECURITY_REPORT) 23:42:37.001 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Decapsulating COMMAND_CLASS_SECURITY 23:42:37.002 [DEBUG] [ommandclass.ZWaveSecurityCommandClass] - NODE 17: SECURITY_RXD 98 07 23:42:37.002 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Incoming command class COMMAND_CLASS_SECURITY, endpoint 0 23:42:37.003 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Received COMMAND_CLASS_SECURITY V0 NETWORK_KEY_VERIFY 23:42:37.003 [DEBUG] [ommandclass.ZWaveSecurityCommandClass] - NODE 17: setupNetworkKey useSchemeZero=false 23:42:37.003 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Commands processed 1. 23:42:37.004 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@79be6126. 23:42:37.004 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Command verified org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@79be6126. 23:42:37.005 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: notifyTransactionResponse TID:83 DONE 23:42:37.010 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1 23:42:37.011 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 23:42:37.011 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:37.011 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 23:42:37.012 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 83: Transaction event listener: DONE: DONE -> 23:42:37.012 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 17: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@694aa53 23:42:37.012 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 17: Node Init transaction completed with response COMPLETE 23:42:37.013 [INFO ] [ialization.ZWaveNodeInitStageAdvancer] - NODE 17: SECURITY_INC State=COMPLETE 23:42:37.013 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 17: SECURITY_INC State=SECURE_PING 23:42:37.013 [DEBUG] [mandclass.impl.CommandClassSecurityV1] - Creating command message SECURITY_NONCE_GET version 1 23:42:37.013 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 17: ZWaveCommandClassTransactionPayload - send to node 23:42:37.014 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: SECURITY check internal 23:42:37.014 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Command Class COMMAND_CLASS_SECURITY is NOT required to be secured 23:42:37.014 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@cc3296c 23:42:37.014 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Bump transaction 86 priority from High to Immediate 23:42:37.015 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Adding to device queue 23:42:37.015 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Added 86 to queue - size 2 23:42:37.015 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 23:42:37.015 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 11 02 98 40 25 47 4C 23:42:37.016 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 17: Sending REQUEST Message = 01 09 00 13 11 02 98 40 25 47 4C 23:42:37.016 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT 23:42:37.016 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 86: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 71 23:42:37.060 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 23:42:37.060 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 23:42:37.061 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 23:42:37.061 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 86: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 71 23:42:37.061 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK 23:42:37.062 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:37.062 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:42:37.104 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 23:42:37.105 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 23:42:37.107 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 23:42:37.108 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 86: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 71 23:42:37.110 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 23:42:37.111 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 86: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 71 23:42:37.113 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 23:42:37.114 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 17: sentData successfully placed on stack. 23:42:37.115 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 86: Advanced to WAIT_REQUEST 23:42:37.116 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: TID 86: Transaction not completed 23:42:37.117 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:37.119 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:42:37.151 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 47 00 00 02 AE 23:42:37.152 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=71, payload=47 00 00 02 23:42:37.155 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=71, payload=47 00 00 02 23:42:37.155 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 86: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 71 23:42:37.156 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 23:42:37.156 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 86: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 71 23:42:37.157 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking TID 86: (Callback 71) 23:42:37.158 [DEBUG] [l.serialmessage.ZWaveCommandProcessor] - Callback match! 23:42:37.158 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Correlated to TID 86: callback 71 23:42:37.159 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=71, payload=47 00 00 02 23:42:37.160 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 17: SendData Request. CallBack ID = 71, Status = Transmission complete and ACK received(0) 23:42:37.160 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 86: Advanced to WAIT_DATA 23:42:37.161 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: TID 86: Transaction not completed 23:42:37.161 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:37.162 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:42:37.195 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 10 00 04 00 11 0A 98 80 13 95 EF 94 71 C8 E9 A4 E1 23:42:37.196 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=17, callback=0, payload=00 11 0A 98 80 13 95 EF 94 71 C8 E9 A4 23:42:37.199 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=17, callback=0, payload=00 11 0A 98 80 13 95 EF 94 71 C8 E9 A4 23:42:37.200 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null 23:42:37.200 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Application Command Request (ALIVE:SECURITY_REPORT) 23:42:37.201 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Incoming command class COMMAND_CLASS_SECURITY, endpoint 0 23:42:37.201 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: SECURITY check internal 23:42:37.202 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Received COMMAND_CLASS_SECURITY V0 SECURITY_NONCE_REPORT 23:42:37.202 [DEBUG] [ommandclass.ZWaveSecurityCommandClass] - NODE 17: NONCE Received start... 23:42:37.203 [DEBUG] [ommandclass.ZWaveSecurityCommandClass] - NODE 17: NONCE Received start null 23:42:37.203 [DEBUG] [ommandclass.ZWaveSecurityCommandClass] - NODE 17: NONCE Received ZWaveNonce [nonceBytes=(13 95 EF 94 71 C8 E9 A4 ), timer=65313, valid=true] 23:42:37.204 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Commands processed 1. 23:42:37.204 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@2304c4fe. 23:42:37.205 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Command verified org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@2304c4fe. 23:42:37.206 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: notifyTransactionResponse TID:86 DONE 23:42:37.206 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1 23:42:37.207 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 23:42:37.207 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:37.208 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 23:42:37.208 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 86: Transaction event listener: DONE: DONE -> 23:42:37.209 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 17: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@32fb35ad 23:42:37.210 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 17: Node Init transaction completed with response COMPLETE 23:42:37.210 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 17: SECURITY_INC State=GET_SECURE_SUPPORTED 23:42:37.211 [DEBUG] [mandclass.impl.CommandClassSecurityV1] - Creating command message SECURITY_COMMANDS_SUPPORTED_GET version 1 23:42:37.211 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 17: ZWaveCommandClassTransactionPayload - send to node 23:42:37.212 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: SECURITY check internal 23:42:37.212 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Command Class COMMAND_CLASS_SECURITY is NOT required to be secured 23:42:37.213 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@3e75e03e 23:42:37.213 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Bump transaction 87 priority from Immediate to Immediate 23:42:37.214 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Adding to device queue 23:42:37.215 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Added 87 to queue - size 2 23:42:37.215 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 23:42:37.215 [DEBUG] [mandclass.impl.CommandClassSecurityV1] - Creating command message SECURITY_MESSAGE_ENCAPSULATION version 1 23:42:37.216 [DEBUG] [ommandclass.ZWaveSecurityCommandClass] - NODE 17: SECURITY_TXD 98 02 23:42:37.218 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 1D 00 13 11 16 98 81 72 B7 79 95 91 3A 13 62 5B A7 F4 13 EB F5 54 F3 77 19 5E 3B 25 48 D8 23:42:37.219 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 17: Sending REQUEST Message = 01 1D 00 13 11 16 98 81 72 B7 79 95 91 3A 13 62 5B A7 F4 13 EB F5 54 F3 77 19 5E 3B 25 48 D8 23:42:37.219 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT 23:42:37.220 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 87: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 72 23:42:37.245 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 23:42:37.246 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 23:42:37.246 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 23:42:37.247 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 87: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 72 23:42:37.247 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK 23:42:37.248 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:37.248 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:42:37.291 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 23:42:37.292 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 23:42:37.292 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 23:42:37.293 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 87: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 72 23:42:37.293 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 23:42:37.294 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 87: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 72 23:42:37.294 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 23:42:37.295 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 17: sentData successfully placed on stack. 23:42:37.295 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 87: Advanced to WAIT_REQUEST 23:42:37.295 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: TID 87: Transaction not completed 23:42:37.295 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:37.295 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:42:37.331 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: WakeupTimerTask 1 Messages waiting, state SECURITY_REPORT 23:42:37.332 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: No more messages, go back to sleep 23:42:37.333 [DEBUG] [.commandclass.ZWaveWakeUpCommandClass] - NODE 17: Creating new message for application command WAKE_UP_NO_MORE_INFORMATION 23:42:37.333 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: SECURITY NOT required on COMMAND_CLASS_WAKE_UP 23:42:37.333 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Command Class COMMAND_CLASS_WAKE_UP is NOT required to be secured 23:42:37.334 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@6306beb9 23:42:37.335 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Bump transaction 88 priority from Immediate to Immediate 23:42:37.336 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 48 00 00 03 A0 23:42:37.337 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=72, payload=48 00 00 03 23:42:37.339 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Adding to device queue 23:42:37.340 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Added 88 to queue - size 2 23:42:37.341 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:42:37.342 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=72, payload=48 00 00 03 23:42:37.343 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 87: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 72 23:42:37.344 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 23:42:37.344 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 87: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 72 23:42:37.345 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking TID 87: (Callback 72) 23:42:37.346 [DEBUG] [l.serialmessage.ZWaveCommandProcessor] - Callback match! 23:42:37.346 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Correlated to TID 87: callback 72 23:42:37.347 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=72, payload=48 00 00 03 23:42:37.347 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 17: SendData Request. CallBack ID = 72, Status = Transmission complete and ACK received(0) 23:42:37.348 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 87: Advanced to WAIT_DATA 23:42:37.349 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: TID 87: Transaction not completed 23:42:37.349 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:37.350 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:42:37.384 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 04 00 11 02 98 40 38 23:42:37.392 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=17, callback=0, payload=00 11 02 98 40 23:42:37.396 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=17, callback=0, payload=00 11 02 98 40 23:42:37.400 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null 23:42:37.412 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Application Command Request (ALIVE:SECURITY_REPORT) 23:42:37.414 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Incoming command class COMMAND_CLASS_SECURITY, endpoint 0 23:42:37.416 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: SECURITY check internal 23:42:37.417 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Received COMMAND_CLASS_SECURITY V0 SECURITY_NONCE_GET 23:42:37.423 [DEBUG] [mandclass.impl.CommandClassSecurityV1] - Creating command message SECURITY_NONCE_REPORT version 1 23:42:37.427 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Added to secure queue - size 1 23:42:37.429 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Commands processed 1. 23:42:37.429 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@48894772. 23:42:37.430 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Command NOT verified org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@48894772. 23:42:37.430 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1 23:42:37.431 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1 23:42:37.431 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:37.431 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:42:37.432 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 11 00 13 11 0A 98 80 0E 87 FB 14 3C D3 BE F0 25 49 55 23:42:37.433 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 17: Sending REQUEST Message = 01 11 00 13 11 0A 98 80 0E 87 FB 14 3C D3 BE F0 25 49 55 23:42:37.433 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT 23:42:37.434 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 89: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 73 23:42:37.437 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 23:42:37.437 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 23:42:37.438 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 23:42:37.438 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 89: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 73 23:42:37.440 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK 23:42:37.442 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:37.444 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 2 out at start. Holdoff false. 23:42:37.478 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 23:42:37.479 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 23:42:37.480 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 23:42:37.480 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 89: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 73 23:42:37.480 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 2 23:42:37.480 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 89: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 73 23:42:37.481 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 23:42:37.481 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 17: sentData successfully placed on stack. 23:42:37.481 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 89: Advanced to WAIT_REQUEST 23:42:37.481 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: TID 89: Transaction not completed 23:42:37.481 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:37.481 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 2 out at start. Holdoff false. 23:42:37.528 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 49 00 00 03 A1 23:42:37.531 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=73, payload=49 00 00 03 23:42:37.536 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=73, payload=49 00 00 03 23:42:37.540 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 89: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 73 23:42:37.541 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 2 23:42:37.542 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 89: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 73 23:42:37.542 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking TID 87: (Callback 72) 23:42:37.543 [DEBUG] [l.serialmessage.ZWaveCommandProcessor] - NO callback match! (72 <> 73) 23:42:37.543 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking TID 89: (Callback 73) 23:42:37.544 [DEBUG] [l.serialmessage.ZWaveCommandProcessor] - Callback match! 23:42:37.545 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Correlated to TID 89: callback 73 23:42:37.547 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=73, payload=49 00 00 03 23:42:37.548 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 17: SendData Request. CallBack ID = 73, Status = Transmission complete and ACK received(0) 23:42:37.549 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 89: Transaction COMPLETED 23:42:37.550 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Response processed after 116ms 23:42:37.550 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: TID 89: Transaction completed 23:42:37.551 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: notifyTransactionResponse TID:89 DONE 23:42:37.552 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:37.552 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:42:37.575 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 2B 00 04 00 11 25 98 81 27 2D B2 B1 F1 C8 C3 78 B7 B2 C6 D4 C8 ED 9F CF 47 4C 72 98 E1 D7 4F 78 72 E7 0E 97 11 44 BD 59 23 5A 9E AE 23:42:37.576 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=17, callback=0, payload=00 11 25 98 81 27 2D B2 B1 F1 C8 C3 78 B7 B2 C6 D4 C8 ED 9F CF 47 4C 72 98 E1 D7 4F 78 72 E7 0E 97 11 44 BD 59 23 5A 9E 23:42:37.576 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=17, callback=0, payload=00 11 25 98 81 27 2D B2 B1 F1 C8 C3 78 B7 B2 C6 D4 C8 ED 9F CF 47 4C 72 98 E1 D7 4F 78 72 E7 0E 97 11 44 BD 59 23 5A 9E 23:42:37.577 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null 23:42:37.577 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Application Command Request (ALIVE:SECURITY_REPORT) 23:42:37.577 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Decapsulating COMMAND_CLASS_SECURITY 23:42:37.578 [DEBUG] [ommandclass.ZWaveSecurityCommandClass] - NODE 17: SECURITY_RXD 98 03 00 86 73 85 8E 59 72 5A 80 84 30 71 31 70 7A 23:42:37.578 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Incoming command class COMMAND_CLASS_SECURITY, endpoint 0 23:42:37.579 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Received COMMAND_CLASS_SECURITY V0 SECURITY_COMMANDS_SUPPORTED_REPORT 23:42:37.579 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Commands processed 1. 23:42:37.579 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@844578f. 23:42:37.580 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Command verified org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@844578f. 23:42:37.580 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: notifyTransactionResponse TID:87 DONE 23:42:37.580 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1 23:42:37.581 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 23:42:37.581 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:37.581 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 23:42:37.582 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 11 02 84 08 25 4A 15 23:42:37.582 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 17: Sending REQUEST Message = 01 09 00 13 11 02 84 08 25 4A 15 23:42:37.583 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT 23:42:37.583 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 88: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 74 23:42:37.584 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 87: Transaction event listener: DONE: DONE -> 23:42:37.584 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 17: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@1d900391 23:42:37.585 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 17: Node Init transaction completed with response COMPLETE 23:42:37.585 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 17: Node advancer - advancing to MANUFACTURER 23:42:37.585 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 17: Node advancer: MANUFACTURER - send ManufacturerSpecific 23:42:37.585 [DEBUG] [ZWaveManufacturerSpecificCommandClass] - NODE 17: Creating new message for command MANUFACTURER_SPECIFIC_GET 23:42:37.586 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 17: ZWaveCommandClassTransactionPayload - send to node 23:42:37.586 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: SECURITY required on COMMAND_CLASS_MANUFACTURER_SPECIFIC 23:42:37.586 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Command Class COMMAND_CLASS_MANUFACTURER_SPECIFIC is required to be secured 23:42:37.587 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@88dd106 23:42:37.587 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Bump transaction 90 priority from Config to Immediate 23:42:37.588 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Adding to device queue 23:42:37.588 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Added 90 to queue - size 2 23:42:37.588 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:42:37.632 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 23:42:37.632 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 23:42:37.632 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 23:42:37.632 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 88: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 74 23:42:37.633 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK 23:42:37.633 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:37.633 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:42:37.676 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 23:42:37.678 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 23:42:37.681 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 23:42:37.683 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 88: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 74 23:42:37.687 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 23:42:37.690 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 88: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 74 23:42:37.692 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 23:42:37.694 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 17: sentData successfully placed on stack. 23:42:37.695 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 88: Advanced to WAIT_REQUEST 23:42:37.696 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: TID 88: Transaction not completed 23:42:37.697 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:37.698 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:42:37.723 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 4A 00 00 02 A3 23:42:37.724 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=74, payload=4A 00 00 02 23:42:37.725 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=74, payload=4A 00 00 02 23:42:37.726 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 88: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 74 23:42:37.727 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 23:42:37.728 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 88: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 74 23:42:37.729 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking TID 88: (Callback 74) 23:42:37.729 [DEBUG] [l.serialmessage.ZWaveCommandProcessor] - Callback match! 23:42:37.731 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Correlated to TID 88: callback 74 23:42:37.732 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=74, payload=4A 00 00 02 23:42:37.733 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 17: SendData Request. CallBack ID = 74, Status = Transmission complete and ACK received(0) 23:42:37.734 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 88: Transaction COMPLETED 23:42:37.735 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Response processed after 152ms 23:42:37.735 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: TID 88: Transaction completed 23:42:37.736 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: notifyTransactionResponse TID:88 DONE 23:42:37.737 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:37.738 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 23:42:37.738 [DEBUG] [ommandclass.ZWaveSecurityCommandClass] - NODE 17: isNonceAvailable = null 23:42:37.739 [DEBUG] [mandclass.impl.CommandClassSecurityV1] - Creating command message SECURITY_NONCE_GET version 1 23:42:37.739 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 11 02 98 40 25 4B 40 23:42:37.740 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 17: Sending REQUEST Message = 01 09 00 13 11 02 98 40 25 4B 40 23:42:37.740 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT 23:42:37.741 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 91: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 75 23:42:37.742 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 88: Transaction event listener: DONE: DONE -> 23:42:37.744 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Went to sleep COMPLETE 23:42:37.777 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 23:42:37.778 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 23:42:37.778 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 23:42:37.778 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 91: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 75 23:42:37.779 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK 23:42:37.779 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:37.779 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:42:37.820 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 23:42:37.821 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 23:42:37.824 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 23:42:37.825 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 91: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 75 23:42:37.826 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 23:42:37.828 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 91: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 75 23:42:37.829 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 23:42:37.832 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 17: sentData successfully placed on stack. 23:42:37.833 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 91: Advanced to WAIT_REQUEST 23:42:37.836 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: TID 91: Transaction not completed 23:42:37.837 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:37.839 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:42:37.868 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 4B 00 00 02 A2 23:42:37.869 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=75, payload=4B 00 00 02 23:42:37.873 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=75, payload=4B 00 00 02 23:42:37.875 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 91: [WAIT_REQUEST] priority=High, requiresResponse=true, callback: 75 23:42:37.876 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 23:42:37.877 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 91: [WAIT_REQUEST] priority=High, requiresResponse=true, callback: 75 23:42:37.878 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking TID 91: (Callback 75) 23:42:37.879 [DEBUG] [l.serialmessage.ZWaveCommandProcessor] - Callback match! 23:42:37.880 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Correlated to TID 91: callback 75 23:42:37.880 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=75, payload=4B 00 00 02 23:42:37.882 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 17: SendData Request. CallBack ID = 75, Status = Transmission complete and ACK received(0) 23:42:37.883 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 91: Advanced to WAIT_DATA 23:42:37.884 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: TID 91: Transaction not completed 23:42:37.885 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:37.887 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:42:37.916 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 10 00 04 00 11 0A 98 80 9F 64 6A 60 27 71 8E 17 D6 23:42:37.917 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=17, callback=0, payload=00 11 0A 98 80 9F 64 6A 60 27 71 8E 17 23:42:37.918 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=17, callback=0, payload=00 11 0A 98 80 9F 64 6A 60 27 71 8E 17 23:42:37.918 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null 23:42:37.919 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Application Command Request (ALIVE:MANUFACTURER) 23:42:37.921 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Incoming command class COMMAND_CLASS_SECURITY, endpoint 0 23:42:37.922 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: SECURITY check internal 23:42:37.924 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Received COMMAND_CLASS_SECURITY V0 SECURITY_NONCE_REPORT 23:42:37.925 [DEBUG] [ommandclass.ZWaveSecurityCommandClass] - NODE 17: NONCE Received start... 23:42:37.926 [DEBUG] [ommandclass.ZWaveSecurityCommandClass] - NODE 17: NONCE Received start null 23:42:37.927 [DEBUG] [ommandclass.ZWaveSecurityCommandClass] - NODE 17: NONCE Received ZWaveNonce [nonceBytes=(9F 64 6A 60 27 71 8E 17 ), timer=69495, valid=true] 23:42:37.928 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Commands processed 1. 23:42:37.929 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@2f9a0f0. 23:42:37.930 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Command verified org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@2f9a0f0. 23:42:37.931 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: notifyTransactionResponse TID:91 DONE 23:42:37.932 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1 23:42:37.933 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 23:42:37.934 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:37.934 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 23:42:37.935 [DEBUG] [mandclass.impl.CommandClassSecurityV1] - Creating command message SECURITY_MESSAGE_ENCAPSULATION version 1 23:42:37.936 [DEBUG] [ommandclass.ZWaveSecurityCommandClass] - NODE 17: SECURITY_TXD 72 04 23:42:37.937 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 1D 00 13 11 16 98 81 5B B5 48 8B F6 21 D5 D4 5A 03 F9 9F 1E F1 48 CF E3 2A 89 41 25 4C 2B 23:42:37.937 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 17: Sending REQUEST Message = 01 1D 00 13 11 16 98 81 5B B5 48 8B F6 21 D5 D4 5A 03 F9 9F 1E F1 48 CF E3 2A 89 41 25 4C 2B 23:42:37.937 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT 23:42:37.938 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 90: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 76 23:42:37.972 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 23:42:37.973 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 23:42:37.973 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 23:42:37.974 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 90: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 76 23:42:37.974 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK 23:42:37.974 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:37.975 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:42:38.016 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 23:42:38.017 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 23:42:38.019 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 23:42:38.020 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 90: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 76 23:42:38.021 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 23:42:38.023 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 90: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 76 23:42:38.024 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 23:42:38.025 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 17: sentData successfully placed on stack. 23:42:38.026 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 90: Advanced to WAIT_REQUEST 23:42:38.027 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: TID 90: Transaction not completed 23:42:38.028 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:38.028 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:42:38.065 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 4C 00 00 02 A5 23:42:38.069 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=76, payload=4C 00 00 02 23:42:38.073 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=76, payload=4C 00 00 02 23:42:38.076 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 90: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 76 23:42:38.077 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 23:42:38.079 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 90: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 76 23:42:38.082 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking TID 90: (Callback 76) 23:42:38.085 [DEBUG] [l.serialmessage.ZWaveCommandProcessor] - Callback match! 23:42:38.087 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Correlated to TID 90: callback 76 23:42:38.091 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=76, payload=4C 00 00 02 23:42:38.093 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 17: SendData Request. CallBack ID = 76, Status = Transmission complete and ACK received(0) 23:42:38.097 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 90: Advanced to WAIT_DATA 23:42:38.100 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: TID 90: Transaction not completed 23:42:38.103 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:38.104 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:42:38.116 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 04 00 11 02 98 40 38 23:42:38.117 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=17, callback=0, payload=00 11 02 98 40 23:42:38.118 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=17, callback=0, payload=00 11 02 98 40 23:42:38.119 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null 23:42:38.120 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Application Command Request (ALIVE:MANUFACTURER) 23:42:38.120 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Incoming command class COMMAND_CLASS_SECURITY, endpoint 0 23:42:38.121 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: SECURITY check internal 23:42:38.121 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Received COMMAND_CLASS_SECURITY V0 SECURITY_NONCE_GET 23:42:38.122 [DEBUG] [mandclass.impl.CommandClassSecurityV1] - Creating command message SECURITY_NONCE_REPORT version 1 23:42:38.123 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Added to secure queue - size 1 23:42:38.124 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Commands processed 1. 23:42:38.124 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@7dfa765. 23:42:38.125 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Command NOT verified org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@7dfa765. 23:42:38.125 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1 23:42:38.126 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1 23:42:38.126 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:38.127 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:42:38.127 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 11 00 13 11 0A 98 80 F4 E2 C4 BC B5 A4 5E 07 25 4D B0 23:42:38.128 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 17: Sending REQUEST Message = 01 11 00 13 11 0A 98 80 F4 E2 C4 BC B5 A4 5E 07 25 4D B0 23:42:38.128 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT 23:42:38.128 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 92: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 77 23:42:38.165 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 23:42:38.168 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 23:42:38.171 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 23:42:38.173 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 92: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 77 23:42:38.174 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK 23:42:38.176 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:38.178 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 2 out at start. Holdoff false. 23:42:38.208 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 23:42:38.210 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 23:42:38.212 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 23:42:38.214 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 92: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 77 23:42:38.217 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 2 23:42:38.219 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 92: [WAIT_RESPONSE] priority=NonceResponse, requiresResponse=true, callback: 77 23:42:38.221 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 23:42:38.223 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 17: sentData successfully placed on stack. 23:42:38.224 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 92: Advanced to WAIT_REQUEST 23:42:38.226 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: TID 92: Transaction not completed 23:42:38.227 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:38.228 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 2 out at start. Holdoff false. 23:42:38.256 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 4D 00 00 03 A5 23:42:38.258 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=77, payload=4D 00 00 03 23:42:38.262 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=77, payload=4D 00 00 03 23:42:38.265 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 92: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 77 23:42:38.267 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 2 23:42:38.269 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 92: [WAIT_REQUEST] priority=NonceResponse, requiresResponse=true, callback: 77 23:42:38.271 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking TID 90: (Callback 76) 23:42:38.275 [DEBUG] [l.serialmessage.ZWaveCommandProcessor] - NO callback match! (76 <> 77) 23:42:38.278 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking TID 92: (Callback 77) 23:42:38.281 [DEBUG] [l.serialmessage.ZWaveCommandProcessor] - Callback match! 23:42:38.282 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Correlated to TID 92: callback 77 23:42:38.284 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=77, payload=4D 00 00 03 23:42:38.285 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 17: SendData Request. CallBack ID = 77, Status = Transmission complete and ACK received(0) 23:42:38.286 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 92: Transaction COMPLETED 23:42:38.287 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Response processed after 159ms 23:42:38.288 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: TID 92: Transaction completed 23:42:38.288 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: notifyTransactionResponse TID:92 DONE 23:42:38.289 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:38.289 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:42:38.303 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 22 00 04 00 11 1C 98 81 96 37 C1 0C F1 68 4F FF 0A 7F CF B4 00 E1 2D 24 C6 F4 21 30 51 71 CE 18 B1 2A 20 23:42:38.304 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=17, callback=0, payload=00 11 1C 98 81 96 37 C1 0C F1 68 4F FF 0A 7F CF B4 00 E1 2D 24 C6 F4 21 30 51 71 CE 18 B1 2A 23:42:38.304 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=17, callback=0, payload=00 11 1C 98 81 96 37 C1 0C F1 68 4F FF 0A 7F CF B4 00 E1 2D 24 C6 F4 21 30 51 71 CE 18 B1 2A 23:42:38.305 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null 23:42:38.305 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Application Command Request (ALIVE:MANUFACTURER) 23:42:38.305 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Decapsulating COMMAND_CLASS_SECURITY 23:42:38.306 [DEBUG] [ommandclass.ZWaveSecurityCommandClass] - NODE 17: SECURITY_RXD 72 05 03 71 01 02 00 05 23:42:38.306 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Incoming command class COMMAND_CLASS_MANUFACTURER_SPECIFIC, endpoint 0 23:42:38.307 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Received COMMAND_CLASS_MANUFACTURER_SPECIFIC V0 MANUFACTURER_SPECIFIC_REPORT 23:42:38.307 [DEBUG] [ZWaveManufacturerSpecificCommandClass] - NODE 17: Manufacturer ID = 0x371 23:42:38.308 [DEBUG] [ZWaveManufacturerSpecificCommandClass] - NODE 17: Device Type = 0x102 23:42:38.308 [DEBUG] [ZWaveManufacturerSpecificCommandClass] - NODE 17: Device ID = 0x5 23:42:38.308 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Commands processed 1. 23:42:38.309 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@56fd23b. 23:42:38.309 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Command verified org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@56fd23b. 23:42:38.309 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: notifyTransactionResponse TID:90 DONE 23:42:38.310 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1 23:42:38.310 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 23:42:38.310 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:42:38.311 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 23:42:38.311 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 90: Transaction event listener: DONE: DONE -> 23:42:38.312 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 17: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@6330dbe7 23:42:38.313 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 17: Node Init transaction completed with response COMPLETE 23:42:38.313 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 17: Node advancer - advancing to APP_VERSION 23:42:38.313 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 17: Node advancer: APP_VERSION - send VersionMessage 23:42:38.314 [DEBUG] [commandclass.ZWaveVersionCommandClass] - NODE 17: Creating new message for command VERSION_GET 23:42:38.314 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 17: ZWaveCommandClassTransactionPayload - send to node 23:42:38.314 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: SECURITY required on COMMAND_CLASS_VERSION 23:42:38.314 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Command Class COMMAND_CLASS_VERSION is required to be secured 23:42:38.315 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@7255a3af 23:42:38.315 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Bump transaction 93 priority from Config to Immediate 23:42:38.315 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Adding to device queue 23:42:38.316 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Added 93 to queue - size 2 23:42:38.316 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 23:43:14.021 [INFO ] [smarthome.event.InboxRemovedEvent ] - Discovery Result with UID 'zwave:device:16c934373e7:node17' has been removed. 23:43:14.025 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'zwave:device:16c934373e7:node17' changed from UNINITIALIZED to INITIALIZING 23:43:14.030 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:16c934373e7:node17. 23:43:14.031 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'zwave:device:16c934373e7:node17' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline 23:43:14.033 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 17: MANUFACTURER not set 23:43:14.036 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 17: Controller status changed to ONLINE. 23:43:14.037 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 17: Controller is ONLINE. Starting device initialisation. 23:43:14.039 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'zwave:device:16c934373e7:node17' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE 23:43:14.041 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 17: Updating node properties. 23:43:14.041 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 17: Updating node properties. MAN=881 23:43:14.041 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 17: Updating node properties. MAN=881. SET. Was null 23:43:14.042 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 17: Properties synchronised 23:43:14.042 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 17: Configuration synchronised 23:43:14.043 [DEBUG] [ave.internal.protocol.ZWaveController] - Event listener added. 23:43:14.043 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 17: Initialising Thing Node... 23:43:14.044 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 17: Polling initialised at 1800 seconds - start in 405000 milliseconds. 23:43:14.044 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 17: Device initialisation complete. 23:43:14.045 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing 'zwave:device:16c934373e7:node17' has been updated. 23:43:14.046 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing 'zwave:device:16c934373e7:node17' has been updated. 23:43:14.046 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing 'zwave:device:16c934373e7:node17' has been updated. 23:43:14.046 [INFO ] [smarthome.event.ConfigStatusInfoEvent] - ConfigStatusInfo [configStatusMessages=[]] 23:43:24.976 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0E 00 49 84 11 08 04 07 01 5E 98 9F 55 6C 47 23:43:24.977 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationUpdate[73], type=Request[0], dest=17, callback=132, payload=84 11 08 04 07 01 5E 98 9F 55 6C 23:43:24.978 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationUpdate[73], type=Request[0], dest=17, callback=132, payload=84 11 08 04 07 01 5E 98 9F 55 6C 23:43:24.978 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null 23:43:24.978 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 0 23:43:24.979 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: null 23:43:24.979 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=ApplicationUpdate[73], type=Request[0], dest=17, callback=132, payload=84 11 08 04 07 01 5E 98 9F 55 6C 23:43:24.979 [DEBUG] [message.ApplicationUpdateMessageClass] - NODE 17: Application update request. Node information received. Transaction null 23:43:24.980 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Unsupported command class COMMAND_CLASS_SECURITY_2 23:43:24.980 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Unsupported command class COMMAND_CLASS_TRANSPORT_SERVICE 23:43:24.980 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 17: Unsupported command class COMMAND_CLASS_SUPERVISION 23:43:24.981 [DEBUG] [message.ApplicationUpdateMessageClass] - NODE 17: Application update - no transaction. 23:43:24.981 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:43:24.981 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 23:43:25.257 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Is awake with 1 messages in the queue 23:43:25.257 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Start sleep timer at 5000ms 23:43:25.265 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 17: Got an event from Z-Wave network: ZWaveNodeStatusEvent 23:43:25.267 [DEBUG] [ave.internal.protocol.ZWaveController] - NODE 17: Node Status event - Node is AWAKE 23:43:25.268 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing 'zwave:device:16c934373e7:node17' has been updated. 23:43:26.147 [DEBUG] [zwave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:16c934373e7 23:43:26.149 [DEBUG] [ave.internal.protocol.ZWaveController] - ZWave inclusion process not running - nothing to do 23:43:27.783 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: WakeupTimerTask 1 Messages waiting, state APP_VERSION 23:43:30.284 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: WakeupTimerTask 1 Messages waiting, state APP_VERSION 23:43:30.285 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: No more messages, go back to sleep 23:43:30.286 [DEBUG] [.commandclass.ZWaveWakeUpCommandClass] - NODE 17: Creating new message for application command WAKE_UP_NO_MORE_INFORMATION 23:43:30.287 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: SECURITY required on COMMAND_CLASS_WAKE_UP 23:43:30.288 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Command Class COMMAND_CLASS_WAKE_UP is required to be secured 23:43:30.289 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@69fed5c9 23:43:30.289 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Bump transaction 94 priority from Immediate to Immediate 23:43:30.289 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Adding to device queue 23:43:30.289 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Added 94 to queue - size 3 23:43:30.290 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 23:43:30.290 [DEBUG] [ommandclass.ZWaveSecurityCommandClass] - NODE 17: isNonceAvailable = null 23:43:30.290 [DEBUG] [mandclass.impl.CommandClassSecurityV1] - Creating command message SECURITY_NONCE_GET version 1 23:43:30.290 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 11 02 98 40 25 4E 45 23:43:30.290 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 17: Sending REQUEST Message = 01 09 00 13 11 02 98 40 25 4E 45 23:43:30.291 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT 23:43:30.291 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 95: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 78 23:43:30.293 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 23:43:30.295 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 23:43:30.295 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 23:43:30.295 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 95: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 78 23:43:30.295 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK 23:43:30.295 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:43:30.296 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:43:30.338 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 23:43:30.338 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 23:43:30.339 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 23:43:30.339 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 95: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 78 23:43:30.340 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 23:43:30.340 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 95: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 78 23:43:30.340 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 23:43:30.340 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 17: sentData successfully placed on stack. 23:43:30.341 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 95: Advanced to WAIT_REQUEST 23:43:30.343 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: TID 95: Transaction not completed 23:43:30.343 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:43:30.343 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:43:35.343 [DEBUG] [nsactionManager$ZWaveTransactionTimer] - NODE 17: TID 95: Timeout at state WAIT_REQUEST. 3 retries remaining. 23:43:35.345 [DEBUG] [nsactionManager$ZWaveTransactionTimer] - Aborting Transaction! 23:43:35.346 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 95: Transaction ABORTED 23:43:35.347 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 16 EA 23:43:35.348 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 16 EA 23:43:35.348 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT 23:43:35.349 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:43:35.350 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 23:43:35.412 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 23:43:35.413 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 23:43:35.414 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 95: [ABORTED] priority=High, requiresResponse=true, callback: 78 23:43:35.415 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK 23:43:35.416 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:43:35.416 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:43:35.557 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 4E 01 02 0E A8 23:43:35.561 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=1, callback=78, payload=4E 01 02 0E 23:43:35.564 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=1, callback=78, payload=4E 01 02 0E 23:43:35.569 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 95: [ABORTED] priority=High, requiresResponse=true, callback: 78 23:43:35.571 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 23:43:35.572 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 95: [ABORTED] priority=High, requiresResponse=true, callback: 78 23:43:35.573 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking TID 95: (Callback 78) 23:43:35.574 [DEBUG] [l.serialmessage.ZWaveCommandProcessor] - Callback match! 23:43:35.575 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Correlated to TID 95: callback 78 23:43:35.575 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=78, payload=4E 01 02 0E 23:43:35.576 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 17: SendData Request. CallBack ID = 78, Status = Transmission complete, no ACK received(1) 23:43:35.576 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 95: Transaction CANCELLED 23:43:35.577 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 17: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 23:43:35.577 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: CANCEL while sending message. Requeueing - 2 attempts left! 23:43:35.577 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 95: Transaction RESET with 2 retries remaining. 23:43:35.578 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Adding to device queue 23:43:35.578 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Added 95 to queue - size 3 23:43:35.579 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 23:43:35.579 [DEBUG] [ommandclass.ZWaveSecurityCommandClass] - NODE 17: isNonceAvailable = null 23:43:35.580 [DEBUG] [mandclass.impl.CommandClassSecurityV1] - Creating command message SECURITY_NONCE_GET version 1 23:43:35.580 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 11 02 98 40 25 4F 44 23:43:35.580 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 17: Sending REQUEST Message = 01 09 00 13 11 02 98 40 25 4F 44 23:43:35.581 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT 23:43:35.581 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 96: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 79 23:43:35.581 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: TID 95: Transaction not completed 23:43:35.582 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:43:35.582 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:43:35.613 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 23:43:35.613 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 23:43:35.614 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 23:43:35.614 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 96: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 79 23:43:35.615 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK 23:43:35.615 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:43:35.615 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:43:35.656 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 23:43:35.656 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 23:43:35.656 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 23:43:35.657 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 96: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 79 23:43:35.657 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 23:43:35.657 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 96: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 79 23:43:35.658 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 23:43:35.658 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 17: sentData successfully placed on stack. 23:43:35.665 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 96: Advanced to WAIT_REQUEST 23:43:35.666 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: TID 96: Transaction not completed 23:43:35.670 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:43:35.671 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:43:40.666 [DEBUG] [nsactionManager$ZWaveTransactionTimer] - NODE 17: TID 96: Timeout at state WAIT_REQUEST. 3 retries remaining. 23:43:40.668 [DEBUG] [nsactionManager$ZWaveTransactionTimer] - Aborting Transaction! 23:43:40.673 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 96: Transaction ABORTED 23:43:40.674 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 16 EA 23:43:40.674 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 16 EA 23:43:40.675 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT 23:43:40.676 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:43:40.676 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 23:43:40.677 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 23:43:40.677 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 23:43:40.677 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 96: [ABORTED] priority=High, requiresResponse=true, callback: 79 23:43:40.678 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK 23:43:40.678 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:43:40.678 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:43:40.800 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 4F 01 02 07 A0 23:43:40.803 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=1, callback=79, payload=4F 01 02 07 23:43:40.806 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=1, callback=79, payload=4F 01 02 07 23:43:40.807 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 96: [ABORTED] priority=High, requiresResponse=true, callback: 79 23:43:40.808 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 23:43:40.809 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 96: [ABORTED] priority=High, requiresResponse=true, callback: 79 23:43:40.810 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking TID 96: (Callback 79) 23:43:40.811 [DEBUG] [l.serialmessage.ZWaveCommandProcessor] - Callback match! 23:43:40.812 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Correlated to TID 96: callback 79 23:43:40.813 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=79, payload=4F 01 02 07 23:43:40.814 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 17: SendData Request. CallBack ID = 79, Status = Transmission complete, no ACK received(1) 23:43:40.815 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 96: Transaction CANCELLED 23:43:40.815 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 17: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 23:43:40.816 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: CANCEL while sending message. Requeueing - 2 attempts left! 23:43:40.817 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 96: Transaction RESET with 2 retries remaining. 23:43:40.817 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Adding to device queue 23:43:40.818 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Transaction already in queue - removed original 23:43:40.818 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Added 96 to queue - size 2 23:43:40.819 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 23:43:40.820 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 11 02 98 40 25 51 5A 23:43:40.820 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 17: Sending REQUEST Message = 01 09 00 13 11 02 98 40 25 51 5A 23:43:40.821 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT 23:43:40.825 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 96: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 81 23:43:40.826 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: TID 96: Transaction not completed 23:43:40.826 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:43:40.827 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:43:40.857 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 23:43:40.858 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 23:43:40.858 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 23:43:40.858 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 96: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 81 23:43:40.859 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK 23:43:40.859 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:43:40.859 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:43:40.904 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 23:43:40.904 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 23:43:40.905 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 23:43:40.905 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 96: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 81 23:43:40.905 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 23:43:40.906 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 96: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 81 23:43:40.906 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 23:43:40.906 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 17: sentData successfully placed on stack. 23:43:40.906 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 96: Advanced to WAIT_REQUEST 23:43:40.907 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: TID 96: Transaction not completed 23:43:40.907 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:43:40.907 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:43:45.908 [DEBUG] [nsactionManager$ZWaveTransactionTimer] - NODE 17: TID 96: Timeout at state WAIT_REQUEST. 2 retries remaining. 23:43:45.911 [DEBUG] [nsactionManager$ZWaveTransactionTimer] - Aborting Transaction! 23:43:45.915 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 96: Transaction ABORTED 23:43:45.918 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 16 EA 23:43:45.920 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 16 EA 23:43:45.921 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT 23:43:45.922 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:43:45.923 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 23:43:45.925 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 23:43:45.925 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 23:43:45.926 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 96: [ABORTED] priority=High, requiresResponse=true, callback: 81 23:43:45.926 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK 23:43:45.927 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:43:45.927 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:43:46.051 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 51 01 02 07 BE 23:43:46.053 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=1, callback=81, payload=51 01 02 07 23:43:46.059 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=1, callback=81, payload=51 01 02 07 23:43:46.067 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 96: [ABORTED] priority=High, requiresResponse=true, callback: 81 23:43:46.069 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 23:43:46.070 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 96: [ABORTED] priority=High, requiresResponse=true, callback: 81 23:43:46.071 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking TID 96: (Callback 81) 23:43:46.072 [DEBUG] [l.serialmessage.ZWaveCommandProcessor] - Callback match! 23:43:46.072 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Correlated to TID 96: callback 81 23:43:46.073 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=81, payload=51 01 02 07 23:43:46.074 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 17: SendData Request. CallBack ID = 81, Status = Transmission complete, no ACK received(1) 23:43:46.075 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 96: Transaction CANCELLED 23:43:46.075 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 17: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 23:43:46.076 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: CANCEL while sending message. Requeueing - 1 attempts left! 23:43:46.076 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 96: Transaction RESET with 1 retries remaining. 23:43:46.077 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Adding to device queue 23:43:46.077 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Added 96 to queue - size 2 23:43:46.077 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 23:43:46.078 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 11 02 98 40 25 52 59 23:43:46.078 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 17: Sending REQUEST Message = 01 09 00 13 11 02 98 40 25 52 59 23:43:46.079 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT 23:43:46.080 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 96: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 82 23:43:46.080 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: TID 96: Transaction not completed 23:43:46.081 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:43:46.081 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:43:46.105 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 23:43:46.105 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 23:43:46.106 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 23:43:46.106 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 96: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 82 23:43:46.107 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK 23:43:46.107 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:43:46.107 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:43:46.148 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 23:43:46.149 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 23:43:46.149 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 23:43:46.150 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 96: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 82 23:43:46.150 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 23:43:46.151 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 96: [WAIT_RESPONSE] priority=High, requiresResponse=true, callback: 82 23:43:46.151 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 23:43:46.151 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 17: sentData successfully placed on stack. 23:43:46.151 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 96: Advanced to WAIT_REQUEST 23:43:46.152 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: TID 96: Transaction not completed 23:43:46.152 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:43:46.158 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:43:51.153 [DEBUG] [nsactionManager$ZWaveTransactionTimer] - NODE 17: TID 96: Timeout at state WAIT_REQUEST. 1 retries remaining. 23:43:51.154 [DEBUG] [nsactionManager$ZWaveTransactionTimer] - Aborting Transaction! 23:43:51.161 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 96: Transaction ABORTED 23:43:51.163 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 16 EA 23:43:51.164 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 16 EA 23:43:51.166 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT 23:43:51.167 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:43:51.169 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 23:43:51.170 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 23:43:51.172 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 23:43:51.173 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 96: [ABORTED] priority=High, requiresResponse=true, callback: 82 23:43:51.174 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK 23:43:51.175 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:43:51.175 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 23:43:51.245 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 52 01 02 01 BB 23:43:51.248 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=1, callback=82, payload=52 01 02 01 23:43:51.250 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=1, callback=82, payload=52 01 02 01 23:43:51.253 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 96: [ABORTED] priority=High, requiresResponse=true, callback: 82 23:43:51.254 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 23:43:51.255 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 96: [ABORTED] priority=High, requiresResponse=true, callback: 82 23:43:51.256 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking TID 96: (Callback 82) 23:43:51.258 [DEBUG] [l.serialmessage.ZWaveCommandProcessor] - Callback match! 23:43:51.259 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Correlated to TID 96: callback 82 23:43:51.260 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=82, payload=52 01 02 01 23:43:51.261 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 17: SendData Request. CallBack ID = 82, Status = Transmission complete, no ACK received(1) 23:43:51.262 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 96: Transaction CANCELLED 23:43:51.272 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 17: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 23:43:51.273 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: Retry count exceeded. Discarding message: TID 96: [CANCELLED] priority=High, requiresResponse=true, callback: 82 23:43:51.275 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 17: Got an event from Z-Wave network: ZWaveNodeStatusEvent 23:43:51.276 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 17: Setting OFFLINE 23:43:51.278 [DEBUG] [ave.internal.protocol.ZWaveController] - NODE 17: Node Status event - Node is DEAD 23:43:51.278 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'zwave:device:16c934373e7:node17' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Node is not communicating with controller 23:43:51.280 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Node is DEAD. 23:43:51.280 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 17: Got an event from Z-Wave network: ZWaveNodeStatusEvent 23:43:51.281 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 17: Setting OFFLINE 23:43:51.282 [DEBUG] [ave.internal.protocol.ZWaveController] - NODE 17: Node Status event - Node is DEAD 23:43:51.282 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: TID 96: Transaction completed 23:43:51.283 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: notifyTransactionResponse TID:96 CANCELLED 23:43:51.283 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 17: processing secure transaction -- TID:94 23:43:51.283 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 94: Transaction event listener: DONE: UNINTIALIZED -> 23:43:51.283 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Completing UNINTIALIZED transaction 94!!! How?!? 23:43:51.284 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 17: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 23:43:51.284 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 23:43:51.284 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 23:43:51.292 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 17: Went to sleep CANCELLED