I’m also including the debug of an ADD of another Recessed Door Sensor (node#86) However, no node86.xml exists as a result.
DEBUG 2016-09-26 10:57:10,636 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x11, 0x00, 0x4A, 0x16, 0x02, 0x56, 0x0A, 0x04, 0x07, 0x01, 0x5E, 0x86, 0x72, 0x98, 0xEF, 0x5A, 0x82, 0xEB] has been received.
DEBUG 2016-09-26 10:57:10,636 (Z-Wave): RX_Session_Layer : Z-Wave function ‘ZW_AddNodeToNetwork(Mode(s)=[ADD_NODE_ANY, ADD_NODE_OPTION_HIGH_POWER, ADD_NODE_OPTION_NETWORK_WIDE], CallbackID=0x16)’ has received ‘ADD_NODE_STATUS_NODE_FOUND’ callback frame [Status: ADD_NODE_STATUS_NODE_FOUND, Callback ID: 0x16, Node ID: 86, Device Classes: [Basic: 0x04, Generic: 0x07, Specific: 0x01], Command Classes: [Supported: [COMMAND_CLASS_ZWAVEPLUS_INFO, COMMAND_CLASS_VERSION, COMMAND_CLASS_MANUFACTURER_SPECIFIC, COMMAND_CLASS_SECURITY], Controlled: [COMMAND_CLASS_DEVICE_RESET_LOCALLY, COMMAND_CLASS_HAIL]]] --> waiting ‘76,000’ [ms] for ‘ADD_NODE_STATUS_ADDING_SLAVE’ or ‘ADD_NODE_STATUS_ADDING_CONTROLLER’ callback.
DEBUG 2016-09-26 10:57:10,636 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01]
DEBUG 2016-09-26 10:57:10,637 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x11, 0x00, 0x4A, 0x16, 0x03, 0x56, 0x0A, 0x04, 0x07, 0x01]
DEBUG 2016-09-26 10:57:10,638 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x5E]
DEBUG 2016-09-26 10:57:10,638 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x86, 0x72, 0x98, 0xEF, 0x5A, 0x82, 0xEA]
DEBUG 2016-09-26 10:57:10,639 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x11, 0x00, 0x4A, 0x16, 0x03, 0x56, 0x0A, 0x04, 0x07, 0x01, 0x5E, 0x86, 0x72, 0x98, 0xEF, 0x5A, 0x82, 0xEA] has been received.
DEBUG 2016-09-26 10:57:10,641 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01]
DEBUG 2016-09-26 10:57:10,641 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x11, 0x00, 0x4A, 0x16, 0x05, 0x56, 0x0A, 0x04, 0x07, 0x01, 0x5E, 0x86]
DEBUG 2016-09-26 10:57:10,641 (Z-Wave): RX_Session_Layer : Z-Wave function ‘ZW_AddNodeToNetwork(Mode(s)=[ADD_NODE_ANY, ADD_NODE_OPTION_HIGH_POWER, ADD_NODE_OPTION_NETWORK_WIDE], CallbackID=0x16)’ has received ‘ADD_NODE_STATUS_ADDING_SLAVE’ callback frame [Status: ADD_NODE_STATUS_ADDING_SLAVE, Callback ID: 0x16, Node ID: 86, Device Classes: [Basic: 0x04, Generic: 0x07, Specific: 0x01], Command Classes: [Supported: [COMMAND_CLASS_ZWAVEPLUS_INFO, COMMAND_CLASS_VERSION, COMMAND_CLASS_MANUFACTURER_SPECIFIC, COMMAND_CLASS_SECURITY], Controlled: [COMMAND_CLASS_DEVICE_RESET_LOCALLY, COMMAND_CLASS_HAIL]]] --> waiting for ‘ADD_NODE_STATUS_PROTOCOL_DONE’ callback.
DEBUG 2016-09-26 10:57:10,641 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x72]
DEBUG 2016-09-26 10:57:10,641 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x98, 0xEF, 0x5A, 0x82, 0xEC]
DEBUG 2016-09-26 10:57:10,642 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x11, 0x00, 0x4A, 0x16, 0x05, 0x56, 0x0A, 0x04, 0x07, 0x01, 0x5E, 0x86, 0x72, 0x98, 0xEF, 0x5A, 0x82, 0xEC] has been received.
DEBUG 2016-09-26 10:57:10,644 (Z-Wave): RX_Session_Layer : Z-Wave function ‘ZW_AddNodeToNetwork(Mode(s)=[ADD_NODE_ANY, ADD_NODE_OPTION_HIGH_POWER, ADD_NODE_OPTION_NETWORK_WIDE], CallbackID=0x16)’ has received ‘ADD_NODE_STATUS_PROTOCOL_DONE’ callback frame [Status: ADD_NODE_STATUS_PROTOCOL_DONE, Callback ID: 0x16, Node ID: 86, Device Classes: [Basic: 0x04, Generic: 0x07, Specific: 0x01], Command Classes: [Supported: [COMMAND_CLASS_ZWAVEPLUS_INFO, COMMAND_CLASS_VERSION, COMMAND_CLASS_MANUFACTURER_SPECIFIC, COMMAND_CLASS_SECURITY], Controlled: [COMMAND_CLASS_DEVICE_RESET_LOCALLY, COMMAND_CLASS_HAIL]]].
DEBUG 2016-09-26 10:57:10,644 (Z-Wave): TX_Session_Layer : Sending Z-Wave function ‘ZW_AddNodeToNetwork(Mode=ADD_NODE_STOP, callback ID: 0x16)’ call.
DEBUG 2016-09-26 10:57:10,644 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x05, 0x00, 0x4A, 0x05, 0x16, 0xA3].
DEBUG 2016-09-26 10:57:10,645 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06]
DEBUG 2016-09-26 10:57:10,647 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x05, 0x00, 0x4A, 0x05, 0x16, 0xA3] transmission OK.
DEBUG 2016-09-26 10:57:10,647 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function ‘ZW_AddNodeToNetwork(Mode=ADD_NODE_STOP, callback ID: 0x16)’ has been successfully sent --> waiting ‘500’ [ms] for ‘ADD_NODE_STATUS_DONE’ callback.
DEBUG 2016-09-26 10:57:10,696 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01]
DEBUG 2016-09-26 10:57:10,696 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x07, 0x00, 0x4A, 0x16, 0x06, 0x56]
DEBUG 2016-09-26 10:57:10,696 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x00]
DEBUG 2016-09-26 10:57:10,697 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0xF4]
DEBUG 2016-09-26 10:57:10,697 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x07, 0x00, 0x4A, 0x16, 0x06, 0x56, 0x00, 0xF4] has been received.
DEBUG 2016-09-26 10:57:10,697 (Z-Wave): RX_Session_Layer : Callback received [0x01, 0x07, 0x00, 0x4A, 0x16, 0x06, 0x56, 0x00, 0xF4] -> Z-Wave function ‘ZW_AddNodeToNetwork(Mode=ADD_NODE_STOP, callback ID: 0x16)’ successfully executed.
DEBUG 2016-09-26 10:57:10,697 (Z-Wave): TX_Session_Layer : Sending Z-Wave function ‘ZW_AddNodeToNetwork(Mode=ADD_NODE_STOP)’ call.
DEBUG 2016-09-26 10:57:10,698 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x04, 0x00, 0x4A, 0x05, 0xB4].
DEBUG 2016-09-26 10:57:10,699 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06]
DEBUG 2016-09-26 10:57:10,699 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x04, 0x00, 0x4A, 0x05, 0xB4] transmission OK.
DEBUG 2016-09-26 10:57:10,699 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function ‘ZW_AddNodeToNetwork(Mode=ADD_NODE_STOP)’ successfully executed.
DEBUG 2016-09-26 10:57:10,700 (Z-Wave): Inclusion_Manager : Node ‘86’ : [ZWAddNodeToNetwork, Status=ADD_NODE_STATUS_DONE, Supported=[COMMAND_CLASS_ZWAVEPLUS_INFO, COMMAND_CLASS_VERSION, COMMAND_CLASS_MANUFACTURER_SPECIFIC, COMMAND_CLASS_SECURITY], Controlled=[COMMAND_CLASS_DEVICE_RESET_LOCALLY, COMMAND_CLASS_HAIL]]
DEBUG 2016-09-26 10:57:10,700 (Z-Wave): Secure_Inclusion_Manager : Node ‘86’ : [COMMAND_CLASS_SECURITY::SECURITY_SCHEME_GET]
DEBUG 2016-09-26 10:57:10,700 (Z-Wave): Controller_API : Enqueue (queue count=1) Z-Wave function call ‘ZW_SendData(NodeID=86, Payload=[0x98, 0x04, 0x00], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)’.
DEBUG 2016-09-26 10:57:10,700 (Z-Wave): Controller_API : Dequeue (queue count=0) Z-Wave function call ‘ZW_SendData(NodeID=86, Payload=[0x98, 0x04, 0x00], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)’.
DEBUG 2016-09-26 10:57:10,700 (Z-Wave): TX_Session_Layer : Executing Z-Wave function call ‘ZW_SendData(NodeID=86, Payload=[0x98, 0x04, 0x00], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)’…
DEBUG 2016-09-26 10:57:10,700 (Z-Wave): TX_Session_Layer : Send (repeat count=1) Z-Wave function ‘ZW_SendData(NodeID=86, Payload=[0x98, 0x04, 0x00], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x17)’ request (callback ID=0x17).
DEBUG 2016-09-26 10:57:10,701 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x0A, 0x00, 0x13, 0x56, 0x03, 0x98, 0x04, 0x00, 0x05, 0x17, 0x3D].
DEBUG 2016-09-26 10:57:10,702 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06]
DEBUG 2016-09-26 10:57:10,703 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x0A, 0x00, 0x13, 0x56, 0x03, 0x98, 0x04, 0x00, 0x05, 0x17, 0x3D] transmission OK.
DEBUG 2016-09-26 10:57:10,703 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function ‘ZW_SendData(NodeID=86, Payload=[0x98, 0x04, 0x00], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x17)’ has been successfully sent - waiting 5,000 [ms] for response frame.
DEBUG 2016-09-26 10:57:10,711 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01]
DEBUG 2016-09-26 10:57:10,712 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x04, 0x01, 0x13, 0x01, 0xE8]
DEBUG 2016-09-26 10:57:10,712 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] has been received.
DEBUG 2016-09-26 10:57:10,712 (Z-Wave): RX_Session_Layer : ‘ZW_SendData’ response [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] with status ‘RETURN_VALUE_TRUE’ received (callback ID=0x17).
DEBUG 2016-09-26 10:57:10,712 (Z-Wave): RX_Session_Layer : Waiting 64,989 [ms] for ‘ZW_SendData’ callback frame (callback ID=0x17).
DEBUG 2016-09-26 10:57:10,727 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01]
DEBUG 2016-09-26 10:57:10,728 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x07, 0x00, 0x13, 0x17, 0x00, 0x00, 0x02]
DEBUG 2016-09-26 10:57:10,728 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0xFE]
DEBUG 2016-09-26 10:57:10,728 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x07, 0x00, 0x13, 0x17, 0x00, 0x00, 0x02, 0xFE] has been received.
DEBUG 2016-09-26 10:57:10,729 (Z-Wave): RX_Session_Layer : Callback [0x01, 0x07, 0x00, 0x13, 0x17, 0x00, 0x00, 0x02, 0xFE] (callback ID=0x17) with state ‘TRANSMIT_COMPLETE_OK’ received -> Z-Wave function ‘ZW_SendData(NodeID=86, Payload=[0x98, 0x04, 0x00], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x17)’ successfully executed.
DEBUG 2016-09-26 10:57:10,753 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01]
DEBUG 2016-09-26 10:57:10,753 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x09, 0x00, 0x04]
DEBUG 2016-09-26 10:57:10,753 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x00]
DEBUG 2016-09-26 10:57:10,754 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x56, 0x03, 0x98, 0x05, 0x00, 0x3A]
DEBUG 2016-09-26 10:57:10,754 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x09, 0x00, 0x04, 0x00, 0x56, 0x03, 0x98, 0x05, 0x00, 0x3A] has been received.
DEBUG 2016-09-26 10:57:10,754 (Z-Wave): Secure_Inclusion_Manager : Node ‘86’ : [COMMAND_CLASS_SECURITY::SECURITY_SCHEME_REPORT, Schemes=[SECURITY_SCHEME_0]]
DEBUG 2016-09-26 10:57:10,754 (Z-Wave): Secure_Inclusion_Manager : Node ‘86’ : [COMMAND_CLASS_SECURITY::SECURITY_KEY_SET, Key=[0x01, 0x02, 0x03, 0x04, 0x05, 0x06, 0x07, 0x08, 0x01, 0x02, 0x03, 0x04, 0x05, 0x06, 0x07, 0x08]]
DEBUG 2016-09-26 10:57:10,754 (Z-Wave): Controller_API : Enqueue (queue count=1) Z-Wave function call ‘<SECURITY_ENCAPSULATION>ZW_SendData(NodeID=86, Payload=[0x98, 0x06, 0x01, 0x02, 0x03, 0x04, 0x05, 0x06, 0x07, 0x08, 0x01, 0x02, 0x03, 0x04, 0x05, 0x06, 0x07, 0x08], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)<SECURITY_ENCAPSULATION>’.
DEBUG 2016-09-26 10:57:10,754 (Z-Wave): Controller_API : Dequeue (queue count=0) Z-Wave function call ‘<SECURITY_ENCAPSULATION>ZW_SendData(NodeID=86, Payload=[0x98, 0x06, 0x01, 0x02, 0x03, 0x04, 0x05, 0x06, 0x07, 0x08, 0x01, 0x02, 0x03, 0x04, 0x05, 0x06, 0x07, 0x08], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)<SECURITY_ENCAPSULATION>’.
DEBUG 2016-09-26 10:57:10,754 (Z-Wave): TX_Session_Layer : Executing Z-Wave function call ‘<SECURITY_ENCAPSULATION>ZW_SendData(NodeID=86, Payload=[0x98, 0x06, 0x01, 0x02, 0x03, 0x04, 0x05, 0x06, 0x07, 0x08, 0x01, 0x02, 0x03, 0x04, 0x05, 0x06, 0x07, 0x08], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)<SECURITY_ENCAPSULATION>’…
DEBUG 2016-09-26 10:57:10,754 (Z-Wave): CCSecurityFuncDecorator : Node ‘86’ : [COMMAND_CLASS_SECURITY::SECURITY_NONCE_GET]
DEBUG 2016-09-26 10:57:10,755 (Z-Wave): TX_Session_Layer : Send (repeat count=1) Z-Wave function ‘ZW_SendData(NodeID=86, Payload=[0x98, 0x40], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x18)’ request (callback ID=0x18).
DEBUG 2016-09-26 10:57:10,755 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x09, 0x00, 0x13, 0x56, 0x02, 0x98, 0x40, 0x05, 0x18, 0x74].
DEBUG 2016-09-26 10:57:10,755 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01]
DEBUG 2016-09-26 10:57:10,756 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x07, 0x00, 0x4A, 0x16, 0x06]
DEBUG 2016-09-26 10:57:10,756 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x56]
DEBUG 2016-09-26 10:57:10,756 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x00, 0xF4]
DEBUG 2016-09-26 10:57:10,757 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x07, 0x00, 0x4A, 0x16, 0x06, 0x56, 0x00, 0xF4] has been received.
DEBUG 2016-09-26 10:57:10,757 (Z-Wave): RX_Session_Layer : Received an unexpected frame [0x01, 0x07, 0x00, 0x4A, 0x16, 0x06, 0x56, 0x00, 0xF4] while waiting for an ACK of the Z-Wave function ‘ZW_SendData(NodeID=86, Payload=[0x98, 0x40], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x18)’.
DEBUG 2016-09-26 10:57:10,757 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x18]
DEBUG 2016-09-26 10:57:10,758 (Z-Wave): RX_Frame_Layer : CAN -> Failed to send data frame [0x01, 0x09, 0x00, 0x13, 0x56, 0x02, 0x98, 0x40, 0x05, 0x18, 0x74] because the Z-Wave firmware has an ACK expected instead of the sent frame
DEBUG 2016-09-26 10:57:10,758 (Z-Wave): TX_Frame_Layer : CAN -> Wait 100 [ms] before next retransmission attempt.
DEBUG 2016-09-26 10:57:10,858 (Z-Wave): TX_Frame_Layer : Retransmission attempt 1, data frame [0x01, 0x09, 0x00, 0x13, 0x56, 0x02, 0x98, 0x40, 0x05, 0x18, 0x74]
DEBUG 2016-09-26 10:57:10,861 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06]
DEBUG 2016-09-26 10:57:10,861 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x09, 0x00, 0x13, 0x56, 0x02, 0x98, 0x40, 0x05, 0x18, 0x74] transmission OK.
DEBUG 2016-09-26 10:57:10,861 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function ‘ZW_SendData(NodeID=86, Payload=[0x98, 0x40], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x18)’ has been successfully sent - waiting 5,000 [ms] for response frame.
DEBUG 2016-09-26 10:57:10,866 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01]
DEBUG 2016-09-26 10:57:10,866 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x04, 0x01, 0x13, 0x01, 0xE8]
DEBUG 2016-09-26 10:57:10,866 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] has been received.
DEBUG 2016-09-26 10:57:10,866 (Z-Wave): RX_Session_Layer : ‘ZW_SendData’ response [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] with status ‘RETURN_VALUE_TRUE’ received (callback ID=0x18).
DEBUG 2016-09-26 10:57:10,866 (Z-Wave): RX_Session_Layer : Waiting 64,889 [ms] for ‘ZW_SendData’ callback frame (callback ID=0x18).
DEBUG 2016-09-26 10:57:10,881 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01]
DEBUG 2016-09-26 10:57:10,882 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x07, 0x00, 0x13, 0x18, 0x00, 0x00, 0x02]
DEBUG 2016-09-26 10:57:10,882 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0xF1]
DEBUG 2016-09-26 10:57:10,883 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x07, 0x00, 0x13, 0x18, 0x00, 0x00, 0x02, 0xF1] has been received.
DEBUG 2016-09-26 10:57:10,883 (Z-Wave): RX_Session_Layer : Callback [0x01, 0x07, 0x00, 0x13, 0x18, 0x00, 0x00, 0x02, 0xF1] (callback ID=0x18) with state ‘TRANSMIT_COMPLETE_OK’ received -> Z-Wave function ‘ZW_SendData(NodeID=86, Payload=[0x98, 0x40], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x18)’ successfully executed.
DEBUG 2016-09-26 10:57:10,911 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01]
DEBUG 2016-09-26 10:57:10,911 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x10, 0x00, 0x04, 0x00, 0x56, 0x0A, 0x98]
DEBUG 2016-09-26 10:57:10,911 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x80]
DEBUG 2016-09-26 10:57:10,912 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x0D, 0x14, 0x64, 0x02, 0xD6, 0x79, 0x41, 0x85, 0xBB]
DEBUG 2016-09-26 10:57:10,912 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x10, 0x00, 0x04, 0x00, 0x56, 0x0A, 0x98, 0x80, 0x0D, 0x14, 0x64, 0x02, 0xD6, 0x79, 0x41, 0x85, 0xBB] has been received.
DEBUG 2016-09-26 10:57:10,912 (Z-Wave): CCSecurityFuncDecorator : Node ‘86’ : [COMMAND_CLASS_SECURITY::SECURITY_NONCE_REPORT, Nonce=[0D, 14, 64, 02, D6, 79, 41, 85]]
DEBUG 2016-09-26 10:57:10,912 (Z-Wave): TX_Session_Layer : Send (repeat count=1) Z-Wave function ‘ZW_SendData(NodeID=86, Payload=[0x98, 0x06, 0x01, 0x02, 0x03, 0x04, 0x05, 0x06, 0x07, 0x08, 0x01, 0x02, 0x03, 0x04, 0x05, 0x06, 0x07, 0x08], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x19)’ request (callback ID=0x19).
DEBUG 2016-09-26 10:57:10,913 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x2D, 0x00, 0x13, 0x56, 0x26, 0x98, 0x81, 0x4A, 0xAB, 0xFC, 0xCD, 0x52, 0x27, 0x08, 0x9A, 0x4A, 0x6C, 0x2F, 0x18, 0x4A, 0x1A, 0x2E, 0xF4, 0x39, 0xE9, 0x66, 0x0F, 0xF2, 0x04, 0x9C, 0x4A, 0x04, 0xF6, 0x5B, 0x0D, 0x76, 0x04, 0xEC, 0xFD, 0x25, 0x56, 0x49, 0x92, 0x05, 0x19, 0xEE].
DEBUG 2016-09-26 10:57:10,919 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06]
DEBUG 2016-09-26 10:57:10,920 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x2D, 0x00, 0x13, 0x56, 0x26, 0x98, 0x81, 0x4A, 0xAB, 0xFC, 0xCD, 0x52, 0x27, 0x08, 0x9A, 0x4A, 0x6C, 0x2F, 0x18, 0x4A, 0x1A, 0x2E, 0xF4, 0x39, 0xE9, 0x66, 0x0F, 0xF2, 0x04, 0x9C, 0x4A, 0x04, 0xF6, 0x5B, 0x0D, 0x76, 0x04, 0xEC, 0xFD, 0x25, 0x56, 0x49, 0x92, 0x05, 0x19, 0xEE] transmission OK.
DEBUG 2016-09-26 10:57:10,920 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function ‘ZW_SendData(NodeID=86, Payload=[0x98, 0x06, 0x01, 0x02, 0x03, 0x04, 0x05, 0x06, 0x07, 0x08, 0x01, 0x02, 0x03, 0x04, 0x05, 0x06, 0x07, 0x08], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x19)’ has been successfully sent - waiting 5,000 [ms] for response frame.
DEBUG 2016-09-26 10:57:10,926 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01]
DEBUG 2016-09-26 10:57:10,926 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x04, 0x01, 0x13, 0x01]
DEBUG 2016-09-26 10:57:10,926 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0xE8]
DEBUG 2016-09-26 10:57:10,927 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] has been received.
DEBUG 2016-09-26 10:57:10,927 (Z-Wave): RX_Session_Layer : ‘ZW_SendData’ response [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] with status ‘RETURN_VALUE_TRUE’ received (callback ID=0x19).
DEBUG 2016-09-26 10:57:10,927 (Z-Wave): RX_Session_Layer : Waiting 64,986 [ms] for ‘ZW_SendData’ callback frame (callback ID=0x19).
DEBUG 2016-09-26 10:57:10,944 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01]
DEBUG 2016-09-26 10:57:10,945 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x07, 0x00, 0x13, 0x19, 0x00, 0x00, 0x03]
DEBUG 2016-09-26 10:57:10,945 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0xF1]
DEBUG 2016-09-26 10:57:10,945 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x07, 0x00, 0x13, 0x19, 0x00, 0x00, 0x03, 0xF1] has been received.
DEBUG 2016-09-26 10:57:10,946 (Z-Wave): RX_Session_Layer : Callback [0x01, 0x07, 0x00, 0x13, 0x19, 0x00, 0x00, 0x03, 0xF1] (callback ID=0x19) with state ‘TRANSMIT_COMPLETE_OK’ received -> Z-Wave function ‘ZW_SendData(NodeID=86, Payload=[0x98, 0x06, 0x01, 0x02, 0x03, 0x04, 0x05, 0x06, 0x07, 0x08, 0x01, 0x02, 0x03, 0x04, 0x05, 0x06, 0x07, 0x08], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x19)’ successfully executed.
ERROR 2016-09-26 10:57:15,947 (Z-Wave): Secure_Inclusion_Manager : Node ‘86’ : [COMMAND_CLASS_SECURITY::SECURITY_KEY_SET, Key=[0x01, 0x02, 0x03, 0x04, 0x05, 0x06, 0x07, 0x08, 0x01, 0x02, 0x03, 0x04, 0x05, 0x06, 0x07, 0x08]] failed : ‘COMMAND_CLASS_REPORT_TIMEOUT_ERROR’.
WARN 2016-09-26 10:57:15,948 (Z-Wave): Inclusion_Manager : Node ‘86’ : The security enabled Z-Wave node has been added to the UNSECURE Z-Wave network because failed to set the network key.
DEBUG 2016-09-26 10:57:15,948 (Z-Wave): Controller : Retrieving Z-Wave node info (ID=86)…
DEBUG 2016-09-26 10:57:15,948 (Z-Wave): Controller_API : Enqueue (queue count=1) Z-Wave function call ‘ZW_GetNodeProtocolInfo(NodeID=86)’.
DEBUG 2016-09-26 10:57:17,949 (Z-Wave): Controller_API : Dequeue (queue count=0) Z-Wave function call ‘ZW_GetNodeProtocolInfo(NodeID=86)’.
DEBUG 2016-09-26 10:57:17,949 (Z-Wave): TX_Session_Layer : Executing Z-Wave function call ‘ZW_GetNodeProtocolInfo(NodeID=86)’…
DEBUG 2016-09-26 10:57:17,949 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x04, 0x00, 0x41, 0x56, 0xEC].
DEBUG 2016-09-26 10:57:17,950 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06]
DEBUG 2016-09-26 10:57:17,950 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x04, 0x00, 0x41, 0x56, 0xEC] transmission OK.
DEBUG 2016-09-26 10:57:17,950 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function ‘ZW_GetNodeProtocolInfo(NodeID=86)’ has been successfully sent - waiting 5,000 [ms] for response frame.
DEBUG 2016-09-26 10:57:17,951 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01]
DEBUG 2016-09-26 10:57:17,951 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x09, 0x01, 0x41, 0x53, 0x9C, 0x01, 0x04]
DEBUG 2016-09-26 10:57:17,952 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x07]
DEBUG 2016-09-26 10:57:17,952 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01, 0x7A]
DEBUG 2016-09-26 10:57:17,952 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x09, 0x01, 0x41, 0x53, 0x9C, 0x01, 0x04, 0x07, 0x01, 0x7A] has been received.
DEBUG 2016-09-26 10:57:17,953 (Z-Wave): RX_Session_Layer : Response received [0x01, 0x09, 0x01, 0x41, 0x53, 0x9C, 0x01, 0x04, 0x07, 0x01, 0x7A] -> Z-Wave function ‘ZW_GetNodeProtocolInfo(NodeID=86)’ successfully executed.
DEBUG 2016-09-26 10:57:17,953 (Z-Wave): Node_Initializer : Node ‘86’ : [ZW_RequestNodeInfo] - check if battery powered device is awake…
DEBUG 2016-09-26 10:57:17,953 (Z-Wave): Controller_API : Enqueue (queue count=1) Z-Wave function call ‘ZW_RequestNodeInfo(NodeID=86)’.
DEBUG 2016-09-26 10:57:17,953 (Z-Wave): Controller_API : Dequeue (queue count=0) Z-Wave function call ‘ZW_RequestNodeInfo(NodeID=86)’.
DEBUG 2016-09-26 10:57:17,953 (Z-Wave): TX_Session_Layer : Executing Z-Wave function call ‘ZW_RequestNodeInfo(NodeID=86)’…
INFO 2016-09-26 10:57:17,953 (Z-Wave): Controller : Z-Wave node info (ID=86) : [[Device Classes : ‘BASIC_TYPE_ROUTING_SLAVE’,‘GENERIC_TYPE_SENSOR_NOTIFICATION’,‘SPECIFIC_TYPE_NOTIFICATION_SENSOR’],[Capabilities : ‘NODEINFO_CAPABILITY_ROUTING’],[Security : ‘NODEINFO_SECURITY_OPTIONAL_FUNC_SUPPORT’]].
DEBUG 2016-09-26 10:57:17,954 (Z-Wave): ZW_RequestNodeInfo : Sending Z-Wave function ‘ZW_RequestNodeInfo(NodeID=86)’ call.
DEBUG 2016-09-26 10:57:17,954 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x04, 0x00, 0x60, 0x56, 0xCD].
DEBUG 2016-09-26 10:57:17,955 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06]
DEBUG 2016-09-26 10:57:17,955 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x04, 0x00, 0x60, 0x56, 0xCD] transmission OK.
DEBUG 2016-09-26 10:57:17,955 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function ‘ZW_RequestNodeInfo(NodeID=86)’ has been successfully sent - waiting 5,000 [ms] for response frame.
DEBUG 2016-09-26 10:57:17,961 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01]
DEBUG 2016-09-26 10:57:17,962 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x04, 0x01, 0x60, 0x01, 0x9B]
DEBUG 2016-09-26 10:57:17,962 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x04, 0x01, 0x60, 0x01, 0x9B] has been received.
DEBUG 2016-09-26 10:57:17,962 (Z-Wave): RX_Session_Layer : Response received [0x01, 0x04, 0x01, 0x60, 0x01, 0x9B] -> Waiting 65,000 [ms] for callback of Z-Wave function call ‘ZW_RequestNodeInfo(NodeID=86)’.
DEBUG 2016-09-26 10:57:20,108 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01]
DEBUG 2016-09-26 10:57:20,109 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x10, 0x00, 0x49, 0x84, 0x56, 0x0A, 0x04]
DEBUG 2016-09-26 10:57:20,109 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x07]
DEBUG 2016-09-26 10:57:20,109 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01, 0x5E, 0x86, 0x72, 0x98, 0xEF, 0x5A, 0x82, 0x79]
DEBUG 2016-09-26 10:57:20,109 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x10, 0x00, 0x49, 0x84, 0x56, 0x0A, 0x04, 0x07, 0x01, 0x5E, 0x86, 0x72, 0x98, 0xEF, 0x5A, 0x82, 0x79] has been received.
DEBUG 2016-09-26 10:57:20,109 (Z-Wave): RX_Session_Layer : Callback received [0x01, 0x10, 0x00, 0x49, 0x84, 0x56, 0x0A, 0x04, 0x07, 0x01, 0x5E, 0x86, 0x72, 0x98, 0xEF, 0x5A, 0x82, 0x79] -> Z-Wave function ‘ZW_RequestNodeInfo(NodeID=86)’ successfully executed.
DEBUG 2016-09-26 10:57:20,110 (Z-Wave): Node_Initializer : Node ‘86’ : [ZW_RequestNodeInfo] succeeded --> node is awake : [Status: UPDATE_STATE_NODE_INFO_RECEIVED, Node ID: 86, Device Classes: [Basic: BASIC_TYPE_ROUTING_SLAVE, Generic: GENERIC_TYPE_SENSOR_NOTIFICATION, Specific: SPECIFIC_TYPE_NOTIFICATION_SENSOR], Command Classes: [Supported: [COMMAND_CLASS_ZWAVEPLUS_INFO, COMMAND_CLASS_VERSION, COMMAND_CLASS_MANUFACTURER_SPECIFIC, COMMAND_CLASS_SECURITY], Controlled: [COMMAND_CLASS_DEVICE_RESET_LOCALLY, COMMAND_CLASS_HAIL]]].
DEBUG 2016-09-26 10:57:20,110 (Z-Wave): Node_Initializer : Node ‘86’ : [ZW_RequestNodeInfo, (Retry=‘2’)]
DEBUG 2016-09-26 10:57:20,110 (Z-Wave): Controller_API : Enqueue (queue count=1) Z-Wave function call ‘ZW_RequestNodeInfo(NodeID=86)’.
DEBUG 2016-09-26 10:57:20,110 (Z-Wave): Controller_API : Dequeue (queue count=0) Z-Wave function call ‘ZW_RequestNodeInfo(NodeID=86)’.
DEBUG 2016-09-26 10:57:20,112 (Z-Wave): TX_Session_Layer : Executing Z-Wave function call ‘ZW_RequestNodeInfo(NodeID=86)’…
DEBUG 2016-09-26 10:57:20,112 (Z-Wave): ZW_RequestNodeInfo : Sending Z-Wave function ‘ZW_RequestNodeInfo(NodeID=86)’ call.
DEBUG 2016-09-26 10:57:20,112 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x04, 0x00, 0x60, 0x56, 0xCD].
DEBUG 2016-09-26 10:57:20,114 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06]
DEBUG 2016-09-26 10:57:20,114 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x04, 0x00, 0x60, 0x56, 0xCD] transmission OK.
DEBUG 2016-09-26 10:57:20,114 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function ‘ZW_RequestNodeInfo(NodeID=86)’ has been successfully sent - waiting 5,000 [ms] for response frame.
DEBUG 2016-09-26 10:57:20,123 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01]
DEBUG 2016-09-26 10:57:20,123 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x04, 0x01, 0x60, 0x01, 0x9B]
DEBUG 2016-09-26 10:57:20,123 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x04, 0x01, 0x60, 0x01, 0x9B] has been received.
DEBUG 2016-09-26 10:57:20,124 (Z-Wave): RX_Session_Layer : Response received [0x01, 0x04, 0x01, 0x60, 0x01, 0x9B] -> Waiting 65,000 [ms] for callback of Z-Wave function call ‘ZW_RequestNodeInfo(NodeID=86)’.
DEBUG 2016-09-26 10:57:20,176 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01]
DEBUG 2016-09-26 10:57:20,177 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x10, 0x00, 0x49, 0x84, 0x56, 0x0A, 0x04]
DEBUG 2016-09-26 10:57:20,177 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x07]
DEBUG 2016-09-26 10:57:20,177 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01, 0x5E, 0x86, 0x72, 0x98, 0xEF, 0x5A, 0x82, 0x79]
DEBUG 2016-09-26 10:57:20,177 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x10, 0x00, 0x49, 0x84, 0x56, 0x0A, 0x04, 0x07, 0x01, 0x5E, 0x86, 0x72, 0x98, 0xEF, 0x5A, 0x82, 0x79] has been received.
DEBUG 2016-09-26 10:57:20,177 (Z-Wave): RX_Session_Layer : Callback received [0x01, 0x10, 0x00, 0x49, 0x84, 0x56, 0x0A, 0x04, 0x07, 0x01, 0x5E, 0x86, 0x72, 0x98, 0xEF, 0x5A, 0x82, 0x79] -> Z-Wave function ‘ZW_RequestNodeInfo(NodeID=86)’ successfully executed.
DEBUG 2016-09-26 10:57:20,178 (Z-Wave): Node_Initializer : Node ‘86’ : [ZW_RequestNodeInfo, (Retry=‘2’)] succeeded : [[Status: UPDATE_STATE_NODE_INFO_RECEIVED, Node ID: 86, Device Classes: [Basic: BASIC_TYPE_ROUTING_SLAVE, Generic: GENERIC_TYPE_SENSOR_NOTIFICATION, Specific: SPECIFIC_TYPE_NOTIFICATION_SENSOR], Command Classes: [Supported: [COMMAND_CLASS_ZWAVEPLUS_INFO, COMMAND_CLASS_VERSION, COMMAND_CLASS_MANUFACTURER_SPECIFIC, COMMAND_CLASS_SECURITY], Controlled: [COMMAND_CLASS_DEVICE_RESET_LOCALLY, COMMAND_CLASS_HAIL]]]].
DEBUG 2016-09-26 10:57:20,178 (Z-Wave): Node_Initializer : Node ‘86’ : [ZW_GetNodeProtocolInfo]…
DEBUG 2016-09-26 10:57:20,178 (Z-Wave): Controller_API : Enqueue (queue count=1) Z-Wave function call ‘ZW_GetNodeProtocolInfo(NodeID=86)’.
DEBUG 2016-09-26 10:57:20,178 (Z-Wave): Controller_API : Dequeue (queue count=0) Z-Wave function call ‘ZW_GetNodeProtocolInfo(NodeID=86)’.
DEBUG 2016-09-26 10:57:20,181 (Z-Wave): TX_Session_Layer : Executing Z-Wave function call ‘ZW_GetNodeProtocolInfo(NodeID=86)’…
DEBUG 2016-09-26 10:57:20,181 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x04, 0x00, 0x41, 0x56, 0xEC].
DEBUG 2016-09-26 10:57:20,183 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06]
DEBUG 2016-09-26 10:57:20,185 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x04, 0x00, 0x41, 0x56, 0xEC] transmission OK.
DEBUG 2016-09-26 10:57:20,185 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01, 0x09, 0x01, 0x41, 0x53, 0x9C, 0x01, 0x04]
DEBUG 2016-09-26 10:57:20,185 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function ‘ZW_GetNodeProtocolInfo(NodeID=86)’ has been successfully sent - waiting 5,000 [ms] for response frame.
DEBUG 2016-09-26 10:57:20,185 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x07, 0x01, 0x7A]
DEBUG 2016-09-26 10:57:20,185 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x09, 0x01, 0x41, 0x53, 0x9C, 0x01, 0x04, 0x07, 0x01, 0x7A] has been received.
DEBUG 2016-09-26 10:57:20,186 (Z-Wave): RX_Session_Layer : Response received [0x01, 0x09, 0x01, 0x41, 0x53, 0x9C, 0x01, 0x04, 0x07, 0x01, 0x7A] -> Z-Wave function ‘ZW_GetNodeProtocolInfo(NodeID=86)’ successfully executed.
DEBUG 2016-09-26 10:57:20,186 (Z-Wave): Node_Initializer : Node ‘86’ : [ZW_GetNodeProtocolInfo] : [[Device Classes : ‘BASIC_TYPE_ROUTING_SLAVE’,‘GENERIC_TYPE_SENSOR_NOTIFICATION’,‘SPECIFIC_TYPE_NOTIFICATION_SENSOR’],[Capabilities : ‘NODEINFO_CAPABILITY_ROUTING’],[Security : ‘NODEINFO_SECURITY_OPTIONAL_FUNC_SUPPORT’]].
DEBUG 2016-09-26 10:57:20,186 (Z-Wave): Node_Initializer : Node ‘86’ : [COMMAND_CLASS_SECURITY::SECURITY_COMMAND_SUPPORTED_GET, (Retry=‘1’)]
DEBUG 2016-09-26 10:57:20,186 (Z-Wave): Controller_API : Enqueue (queue count=1) Z-Wave function call ‘<SECURITY_ENCAPSULATION>ZW_SendData(NodeID=86, Payload=[0x98, 0x02], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)<SECURITY_ENCAPSULATION>’.
DEBUG 2016-09-26 10:57:20,186 (Z-Wave): Controller_API : Dequeue (queue count=0) Z-Wave function call ‘<SECURITY_ENCAPSULATION>ZW_SendData(NodeID=86, Payload=[0x98, 0x02], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)<SECURITY_ENCAPSULATION>’.
DEBUG 2016-09-26 10:57:20,186 (Z-Wave): TX_Session_Layer : Executing Z-Wave function call ‘<SECURITY_ENCAPSULATION>ZW_SendData(NodeID=86, Payload=[0x98, 0x02], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)<SECURITY_ENCAPSULATION>’…
DEBUG 2016-09-26 10:57:20,186 (Z-Wave): CCSecurityFuncDecorator : Node ‘86’ : [COMMAND_CLASS_SECURITY::SECURITY_NONCE_GET]
DEBUG 2016-09-26 10:57:20,186 (Z-Wave): TX_Session_Layer : Send (repeat count=1) Z-Wave function ‘ZW_SendData(NodeID=86, Payload=[0x98, 0x40], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x1A)’ request (callback ID=0x1A).
DEBUG 2016-09-26 10:57:20,186 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x09, 0x00, 0x13, 0x56, 0x02, 0x98, 0x40, 0x05, 0x1A, 0x76].
DEBUG 2016-09-26 10:57:20,188 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06]
DEBUG 2016-09-26 10:57:20,188 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01, 0x04]
DEBUG 2016-09-26 10:57:20,188 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x09, 0x00, 0x13, 0x56, 0x02, 0x98, 0x40, 0x05, 0x1A, 0x76] transmission OK.
DEBUG 2016-09-26 10:57:20,188 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function ‘ZW_SendData(NodeID=86, Payload=[0x98, 0x40], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x1A)’ has been successfully sent - waiting 5,000 [ms] for response frame.
DEBUG 2016-09-26 10:57:20,189 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01]
DEBUG 2016-09-26 10:57:20,189 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x13, 0x00, 0xE9]
DEBUG 2016-09-26 10:57:20,189 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x04, 0x01, 0x13, 0x00, 0xE9] has been received.
DEBUG 2016-09-26 10:57:20,189 (Z-Wave): RX_Session_Layer : ‘ZW_SendData’ response [0x01, 0x04, 0x01, 0x13, 0x00, 0xE9] with status ‘RETURN_VALUE_FALSE’ received (callback ID=0x1A).
DEBUG 2016-09-26 10:57:20,306 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01]
DEBUG 2016-09-26 10:57:20,307 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x10]
DEBUG 2016-09-26 10:57:20,307 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x00, 0x49, 0x84, 0x56, 0x0A, 0x04, 0x07]
DEBUG 2016-09-26 10:57:20,308 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01]
DEBUG 2016-09-26 10:57:20,308 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x5E, 0x86, 0x72, 0x98, 0xEF, 0x5A, 0x82, 0x79]
DEBUG 2016-09-26 10:57:20,308 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x10, 0x00, 0x49, 0x84, 0x56, 0x0A, 0x04, 0x07, 0x01, 0x5E, 0x86, 0x72, 0x98, 0xEF, 0x5A, 0x82, 0x79] has been received.
DEBUG 2016-09-26 10:57:20,308 (Z-Wave): RX_Session_Layer : Received an unexpected frame [0x01, 0x10, 0x00, 0x49, 0x84, 0x56, 0x0A, 0x04, 0x07, 0x01, 0x5E, 0x86, 0x72, 0x98, 0xEF, 0x5A, 0x82, 0x79] while sending the Z-Wave function ‘ZW_SendData(NodeID=86, Payload=[0x98, 0x40], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x1A)’.
DEBUG 2016-09-26 10:57:20,309 (Z-Wave): RX_Session_Layer : ‘Application Controller Update’ frame [Status: UPDATE_STATE_NODE_INFO_RECEIVED, Node ID: 86, Device Classes: [Basic: BASIC_TYPE_ROUTING_SLAVE, Generic: GENERIC_TYPE_SENSOR_NOTIFICATION, Specific: SPECIFIC_TYPE_NOTIFICATION_SENSOR], Command Classes: [Supported: [COMMAND_CLASS_ZWAVEPLUS_INFO, COMMAND_CLASS_VERSION, COMMAND_CLASS_MANUFACTURER_SPECIFIC, COMMAND_CLASS_SECURITY], Controlled: [COMMAND_CLASS_DEVICE_RESET_LOCALLY, COMMAND_CLASS_HAIL]]] has been received.
DEBUG 2016-09-26 10:57:20,691 (Z-Wave): TX_Session_Layer : Send (repeat count=2) Z-Wave function ‘ZW_SendData(NodeID=86, Payload=[0x98, 0x40], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x1B)’ request (callback ID=0x1B).
DEBUG 2016-09-26 10:57:20,691 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x09, 0x00, 0x13, 0x56, 0x02, 0x98, 0x40, 0x05, 0x1B, 0x77].
DEBUG 2016-09-26 10:57:20,693 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06]
DEBUG 2016-09-26 10:57:20,695 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x09, 0x00, 0x13, 0x56, 0x02, 0x98, 0x40, 0x05, 0x1B, 0x77] transmission OK.
DEBUG 2016-09-26 10:57:20,695 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function ‘ZW_SendData(NodeID=86, Payload=[0x98, 0x40], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x1B)’ has been successfully sent - waiting 5,000 [ms] for response frame.
DEBUG 2016-09-26 10:57:20,698 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01]
DEBUG 2016-09-26 10:57:20,698 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x04, 0x01, 0x13, 0x01, 0xE8]
DEBUG 2016-09-26 10:57:20,699 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] has been received.
DEBUG 2016-09-26 10:57:20,699 (Z-Wave): RX_Session_Layer : ‘ZW_SendData’ response [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] with status ‘RETURN_VALUE_TRUE’ received (callback ID=0x1B).
DEBUG 2016-09-26 10:57:20,699 (Z-Wave): RX_Session_Layer : Waiting 64,488 [ms] for ‘ZW_SendData’ callback frame (callback ID=0x1B).
DEBUG 2016-09-26 10:57:20,714 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01]
DEBUG 2016-09-26 10:57:20,714 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x07, 0x00, 0x13, 0x1B, 0x00, 0x00, 0x02]
DEBUG 2016-09-26 10:57:20,715 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0xF2]
DEBUG 2016-09-26 10:57:20,715 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x07, 0x00, 0x13, 0x1B, 0x00, 0x00, 0x02, 0xF2] has been received.
DEBUG 2016-09-26 10:57:20,715 (Z-Wave): RX_Session_Layer : Callback [0x01, 0x07, 0x00, 0x13, 0x1B, 0x00, 0x00, 0x02, 0xF2] (callback ID=0x1B) with state ‘TRANSMIT_COMPLETE_OK’ received -> Z-Wave function ‘ZW_SendData(NodeID=86, Payload=[0x98, 0x40], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x1B)’ successfully executed.
DEBUG 2016-09-26 10:57:20,743 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01]
DEBUG 2016-09-26 10:57:20,743 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x10, 0x00, 0x04, 0x00]
DEBUG 2016-09-26 10:57:20,744 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x56]
DEBUG 2016-09-26 10:57:20,744 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x0A, 0x98, 0x80, 0x96, 0x53, 0x95, 0x4C, 0x4F]
DEBUG 2016-09-26 10:57:20,745 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x23]
DEBUG 2016-09-26 10:57:20,745 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x54, 0x38, 0xB3]
DEBUG 2016-09-26 10:57:20,745 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x10, 0x00, 0x04, 0x00, 0x56, 0x0A, 0x98, 0x80, 0x96, 0x53, 0x95, 0x4C, 0x4F, 0x23, 0x54, 0x38, 0xB3] has been received.
DEBUG 2016-09-26 10:57:20,746 (Z-Wave): CCSecurityFuncDecorator : Node ‘86’ : [COMMAND_CLASS_SECURITY::SECURITY_NONCE_REPORT, Nonce=[96, 53, 95, 4C, 4F, 23, 54, 38]]
DEBUG 2016-09-26 10:57:20,746 (Z-Wave): TX_Session_Layer : Send (repeat count=1) Z-Wave function ‘ZW_SendData(NodeID=86, Payload=[0x98, 0x02], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x1C)’ request (callback ID=0x1C).
DEBUG 2016-09-26 10:57:20,747 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x1D, 0x00, 0x13, 0x56, 0x16, 0x98, 0x81, 0x9D, 0xB7, 0xFF, 0x0E, 0xCF, 0xF6, 0xA5, 0x4C, 0xC9, 0x68, 0x9B, 0x96, 0x90, 0xBB, 0x07, 0x4F, 0x64, 0x77, 0x91, 0x12, 0x05, 0x1C, 0xE5].
DEBUG 2016-09-26 10:57:20,751 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06]
DEBUG 2016-09-26 10:57:20,751 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x1D, 0x00, 0x13, 0x56, 0x16, 0x98, 0x81, 0x9D, 0xB7, 0xFF, 0x0E, 0xCF, 0xF6, 0xA5, 0x4C, 0xC9, 0x68, 0x9B, 0x96, 0x90, 0xBB, 0x07, 0x4F, 0x64, 0x77, 0x91, 0x12, 0x05, 0x1C, 0xE5] transmission OK.
DEBUG 2016-09-26 10:57:20,751 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function ‘ZW_SendData(NodeID=86, Payload=[0x98, 0x02], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x1C)’ has been successfully sent - waiting 5,000 [ms] for response frame.
DEBUG 2016-09-26 10:57:20,757 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01]
DEBUG 2016-09-26 10:57:20,757 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x04, 0x01, 0x13, 0x01, 0xE8]
DEBUG 2016-09-26 10:57:20,763 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] has been received.
DEBUG 2016-09-26 10:57:20,763 (Z-Wave): RX_Session_Layer : ‘ZW_SendData’ response [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] with status ‘RETURN_VALUE_TRUE’ received (callback ID=0x1C).
DEBUG 2016-09-26 10:57:20,763 (Z-Wave): RX_Session_Layer : Waiting 64,984 [ms] for ‘ZW_SendData’ callback frame (callback ID=0x1C).
DEBUG 2016-09-26 10:57:20,774 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01]
DEBUG 2016-09-26 10:57:20,775 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x07, 0x00]
DEBUG 2016-09-26 10:57:20,775 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x13]
DEBUG 2016-09-26 10:57:20,775 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x1C, 0x00, 0x00, 0x03, 0xF4]
DEBUG 2016-09-26 10:57:20,775 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x07, 0x00, 0x13, 0x1C, 0x00, 0x00, 0x03, 0xF4] has been received.
DEBUG 2016-09-26 10:57:20,775 (Z-Wave): RX_Session_Layer : Callback [0x01, 0x07, 0x00, 0x13, 0x1C, 0x00, 0x00, 0x03, 0xF4] (callback ID=0x1C) with state ‘TRANSMIT_COMPLETE_OK’ received -> Z-Wave function ‘ZW_SendData(NodeID=86, Payload=[0x98, 0x02], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x1C)’ successfully executed.
ERROR 2016-09-26 10:57:25,777 (Z-Wave): Node_Initializer : Node ‘86’ : [COMMAND_CLASS_SECURITY::SECURITY_COMMAND_SUPPORTED_GET (Retry=‘1’)] failed : ‘COMMAND_CLASS_REPORT_TIMEOUT_ERROR’.
DEBUG 2016-09-26 10:57:25,777 (Z-Wave): Node_Initializer : Node ‘86’ : [COMMAND_CLASS_SECURITY::SECURITY_COMMAND_SUPPORTED_GET, (Retry=‘2’)]
DEBUG 2016-09-26 10:57:25,778 (Z-Wave): Controller_API : Enqueue (queue count=1) Z-Wave function call ‘<SECURITY_ENCAPSULATION>ZW_SendData(NodeID=86, Payload=[0x98, 0x02], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)<SECURITY_ENCAPSULATION>’.
DEBUG 2016-09-26 10:57:27,778 (Z-Wave): Controller_API : Dequeue (queue count=0) Z-Wave function call ‘<SECURITY_ENCAPSULATION>ZW_SendData(NodeID=86, Payload=[0x98, 0x02], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)<SECURITY_ENCAPSULATION>’.
DEBUG 2016-09-26 10:57:27,778 (Z-Wave): TX_Session_Layer : Executing Z-Wave function call ‘<SECURITY_ENCAPSULATION>ZW_SendData(NodeID=86, Payload=[0x98, 0x02], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)<SECURITY_ENCAPSULATION>’…
DEBUG 2016-09-26 10:57:27,778 (Z-Wave): CCSecurityFuncDecorator : Node ‘86’ : [COMMAND_CLASS_SECURITY::SECURITY_NONCE_GET]
DEBUG 2016-09-26 10:57:27,779 (Z-Wave): TX_Session_Layer : Send (repeat count=1) Z-Wave function ‘ZW_SendData(NodeID=86, Payload=[0x98, 0x40], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x1D)’ request (callback ID=0x1D).
DEBUG 2016-09-26 10:57:27,779 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x09, 0x00, 0x13, 0x56, 0x02, 0x98, 0x40, 0x05, 0x1D, 0x71].
DEBUG 2016-09-26 10:57:27,781 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06]
DEBUG 2016-09-26 10:57:27,781 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x09, 0x00, 0x13, 0x56, 0x02, 0x98, 0x40, 0x05, 0x1D, 0x71] transmission OK.
DEBUG 2016-09-26 10:57:27,781 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function ‘ZW_SendData(NodeID=86, Payload=[0x98, 0x40], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x1D)’ has been successfully sent - waiting 5,000 [ms] for response frame.
DEBUG 2016-09-26 10:57:27,786 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01]
DEBUG 2016-09-26 10:57:27,786 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x04]
DEBUG 2016-09-26 10:57:27,787 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01]
DEBUG 2016-09-26 10:57:27,787 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x13, 0x01, 0xE8]
DEBUG 2016-09-26 10:57:27,787 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] has been received.
DEBUG 2016-09-26 10:57:27,787 (Z-Wave): RX_Session_Layer : ‘ZW_SendData’ response [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] with status ‘RETURN_VALUE_TRUE’ received (callback ID=0x1D).
DEBUG 2016-09-26 10:57:27,787 (Z-Wave): RX_Session_Layer : Waiting 64,992 [ms] for ‘ZW_SendData’ callback frame (callback ID=0x1D).
DEBUG 2016-09-26 10:57:32,659 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01]
DEBUG 2016-09-26 10:57:32,659 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x07, 0x00, 0x13, 0x1D, 0x01, 0x01, 0xE8]
DEBUG 2016-09-26 10:57:32,659 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x1E]
DEBUG 2016-09-26 10:57:32,660 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x07, 0x00, 0x13, 0x1D, 0x01, 0x01, 0xE8, 0x1E] has been received.
DEBUG 2016-09-26 10:57:32,660 (Z-Wave): RX_Session_Layer : Callback [0x01, 0x07, 0x00, 0x13, 0x1D, 0x01, 0x01, 0xE8, 0x1E] (callback ID=0x1D) with state ‘TRANSMIT_COMPLETE_NO_ACK’ received -> Failed to execute Z-Wave function ‘ZW_SendData(NodeID=86, Payload=[0x98, 0x40], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x1D)’
ERROR 2016-09-26 10:57:32,660 (Z-Wave): CCSecurityFuncDecorator : Node ‘86’ : [COMMAND_CLASS_SECURITY::SECURITY_NONCE_GET] failed : ‘NO_ACK_ERROR’.
DEBUG 2016-09-26 10:57:32,660 (Z-Wave): TX_Session_Layer : Z-Wave function ‘ZW_SendData(NodeID=86, Payload=[0x98, 0x02], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)’ has been canceled.
ERROR 2016-09-26 10:57:32,660 (Z-Wave): Node_Initializer : Node ‘86’ : [COMMAND_CLASS_SECURITY::SECURITY_COMMAND_SUPPORTED_GET (Retry=‘2’)] failed : ‘NO_ACK_ERROR’.
DEBUG 2016-09-26 10:57:32,660 (Z-Wave): Node_Initializer : Node ‘86’ : [COMMAND_CLASS_SECURITY::SECURITY_COMMAND_SUPPORTED_GET, (Retry=‘3’)]
DEBUG 2016-09-26 10:57:32,661 (Z-Wave): Controller_API : Enqueue (queue count=1) Z-Wave function call ‘<SECURITY_ENCAPSULATION>ZW_SendData(NodeID=86, Payload=[0x98, 0x02], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)<SECURITY_ENCAPSULATION>’.
DEBUG 2016-09-26 10:57:32,661 (Z-Wave): Controller_API : Dequeue (queue count=0) Z-Wave function call ‘<SECURITY_ENCAPSULATION>ZW_SendData(NodeID=86, Payload=[0x98, 0x02], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)<SECURITY_ENCAPSULATION>’.
DEBUG 2016-09-26 10:57:32,661 (Z-Wave): TX_Session_Layer : Executing Z-Wave function call ‘<SECURITY_ENCAPSULATION>ZW_SendData(NodeID=86, Payload=[0x98, 0x02], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)<SECURITY_ENCAPSULATION>’…
DEBUG 2016-09-26 10:57:32,661 (Z-Wave): CCSecurityFuncDecorator : Node ‘86’ : [COMMAND_CLASS_SECURITY::SECURITY_NONCE_GET]
DEBUG 2016-09-26 10:57:32,661 (Z-Wave): TX_Session_Layer : Send (repeat count=1) Z-Wave function ‘ZW_SendData(NodeID=86, Payload=[0x98, 0x40], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x1E)’ request (callback ID=0x1E).
DEBUG 2016-09-26 10:57:32,661 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x09, 0x00, 0x13, 0x56, 0x02, 0x98, 0x40, 0x05, 0x1E, 0x72].
DEBUG 2016-09-26 10:57:32,662 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06]
DEBUG 2016-09-26 10:57:32,663 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x09, 0x00, 0x13, 0x56, 0x02, 0x98, 0x40, 0x05, 0x1E, 0x72] transmission OK.
DEBUG 2016-09-26 10:57:32,663 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function ‘ZW_SendData(NodeID=86, Payload=[0x98, 0x40], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x1E)’ has been successfully sent - waiting 5,000 [ms] for response frame.
DEBUG 2016-09-26 10:57:32,671 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01]
DEBUG 2016-09-26 10:57:32,672 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x04]
DEBUG 2016-09-26 10:57:32,672 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01, 0x13, 0x01, 0xE8]
DEBUG 2016-09-26 10:57:32,672 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] has been received.
DEBUG 2016-09-26 10:57:32,672 (Z-Wave): RX_Session_Layer : ‘ZW_SendData’ response [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] with status ‘RETURN_VALUE_TRUE’ received (callback ID=0x1E).
DEBUG 2016-09-26 10:57:32,672 (Z-Wave): RX_Session_Layer : Waiting 64,989 [ms] for ‘ZW_SendData’ callback frame (callback ID=0x1E).
DEBUG 2016-09-26 10:57:36,989 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01]
DEBUG 2016-09-26 10:57:36,989 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x07, 0x00, 0x13, 0x1E, 0x01, 0x01, 0xB0, 0x45]
DEBUG 2016-09-26 10:57:36,989 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x07, 0x00, 0x13, 0x1E, 0x01, 0x01, 0xB0, 0x45] has been received.
DEBUG 2016-09-26 10:57:36,989 (Z-Wave): RX_Session_Layer : Callback [0x01, 0x07, 0x00, 0x13, 0x1E, 0x01, 0x01, 0xB0, 0x45] (callback ID=0x1E) with state ‘TRANSMIT_COMPLETE_NO_ACK’ received -> Failed to execute Z-Wave function ‘ZW_SendData(NodeID=86, Payload=[0x98, 0x40], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x1E)’
ERROR 2016-09-26 10:57:36,990 (Z-Wave): CCSecurityFuncDecorator : Node ‘86’ : [COMMAND_CLASS_SECURITY::SECURITY_NONCE_GET] failed : ‘NO_ACK_ERROR’.
DEBUG 2016-09-26 10:57:36,990 (Z-Wave): TX_Session_Layer : Z-Wave function ‘ZW_SendData(NodeID=86, Payload=[0x98, 0x02], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)’ has been canceled.
ERROR 2016-09-26 10:57:36,992 (Z-Wave): Node_Initializer : Node ‘86’ : [COMMAND_CLASS_SECURITY::SECURITY_COMMAND_SUPPORTED_GET (Retry=‘3’)] failed : ‘NO_ACK_ERROR’.
DEBUG 2016-09-26 10:57:36,992 (Z-Wave): Node_Initializer : Node ‘86’ : [COMMAND_CLASS_VERSION::VERSION_COMMAND_CLASS_GET (Retry=‘1’), CommandClass=‘COMMAND_CLASS_VERSION’]…
DEBUG 2016-09-26 10:57:36,992 (Z-Wave): Controller_API : Enqueue (queue count=1) Z-Wave function call ‘ZW_SendData(NodeID=86, Payload=[0x86, 0x13, 0x86], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)’.
DEBUG 2016-09-26 10:57:36,993 (Z-Wave): Controller_API : Dequeue (queue count=0) Z-Wave function call ‘ZW_SendData(NodeID=86, Payload=[0x86, 0x13, 0x86], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)’.
DEBUG 2016-09-26 10:57:36,993 (Z-Wave): TX_Session_Layer : Executing Z-Wave function call ‘ZW_SendData(NodeID=86, Payload=[0x86, 0x13, 0x86], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)’…
DEBUG 2016-09-26 10:57:36,993 (Z-Wave): TX_Session_Layer : Send (repeat count=1) Z-Wave function ‘ZW_SendData(NodeID=86, Payload=[0x86, 0x13, 0x86], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x1F)’ request (callback ID=0x1F).
DEBUG 2016-09-26 10:57:36,993 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x0A, 0x00, 0x13, 0x56, 0x03, 0x86, 0x13, 0x86, 0x05, 0x1F, 0xBA].
DEBUG 2016-09-26 10:57:36,996 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06]
DEBUG 2016-09-26 10:57:36,996 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x0A, 0x00, 0x13, 0x56, 0x03, 0x86, 0x13, 0x86, 0x05, 0x1F, 0xBA] transmission OK.
DEBUG 2016-09-26 10:57:36,996 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function ‘ZW_SendData(NodeID=86, Payload=[0x86, 0x13, 0x86], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x1F)’ has been successfully sent - waiting 5,000 [ms] for response frame.
DEBUG 2016-09-26 10:57:37,004 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01]
DEBUG 2016-09-26 10:57:37,004 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x04, 0x01, 0x13, 0x01, 0xE8]
DEBUG 2016-09-26 10:57:37,004 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] has been received.
DEBUG 2016-09-26 10:57:37,005 (Z-Wave): RX_Session_Layer : ‘ZW_SendData’ response [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] with status ‘RETURN_VALUE_TRUE’ received (callback ID=0x1F).
DEBUG 2016-09-26 10:57:37,005 (Z-Wave): RX_Session_Layer : Waiting 64,989 [ms] for ‘ZW_SendData’ callback frame (callback ID=0x1F).
DEBUG 2016-09-26 10:57:41,337 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01]
DEBUG 2016-09-26 10:57:41,338 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x07, 0x00, 0x13, 0x1F, 0x01, 0x01, 0xB2]
DEBUG 2016-09-26 10:57:41,338 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x46]
DEBUG 2016-09-26 10:57:41,338 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x07, 0x00, 0x13, 0x1F, 0x01, 0x01, 0xB2, 0x46] has been received.
DEBUG 2016-09-26 10:57:41,339 (Z-Wave): RX_Session_Layer : Callback [0x01, 0x07, 0x00, 0x13, 0x1F, 0x01, 0x01, 0xB2, 0x46] (callback ID=0x1F) with state ‘TRANSMIT_COMPLETE_NO_ACK’ received -> Failed to execute Z-Wave function ‘ZW_SendData(NodeID=86, Payload=[0x86, 0x13, 0x86], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x1F)’
WARN 2016-09-26 10:57:41,339 (Z-Wave): Node_Initializer : Node ‘86’ : [COMMAND_CLASS_VERSION::VERSION_COMMAND_CLASS_GET (Retry=‘1’), CommandClass=‘COMMAND_CLASS_VERSION’] failed : ‘NO_ACK_ERROR’.
DEBUG 2016-09-26 10:57:41,340 (Z-Wave): Node_Initializer : Node ‘86’ : [COMMAND_CLASS_VERSION::VERSION_COMMAND_CLASS_GET (Retry=‘2’), CommandClass=‘COMMAND_CLASS_VERSION’]…
DEBUG 2016-09-26 10:57:41,340 (Z-Wave): Controller_API_WakeUp_Queue : Node ‘86’ : Enqueue (Count=‘1’) : ‘ZW_SendData(NodeID=86, Payload=[0x86, 0x13, 0x86], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)’.