DEBUG 2019-05-29 08:15:31,713 (Z-Wave): Command_Builder : Building Z-Wave command DEBUG 2019-05-29 08:15:31,713 (Z-Wave): Command_Builder : Z-Wave command: nodeId = '1', endPoint = '0' DEBUG 2019-05-29 08:15:31,713 (Z-Wave): Command_Builder : Z-Wave command: command = NON_SECURE_INCLUSION_MODE_ON DEBUG 2019-05-29 08:15:31,729 (Z-Wave): Controller_API : Enqueue (WORKING-Queue, Count=1) Z-Wave function call 'ZW_AddNodeToNetwork(Mode(s)=[ADD_NODE_ANY, ADD_NODE_OPTION_HIGH_POWER, ADD_NODE_OPTION_NETWORK_WIDE], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:31,729 (Z-Wave): Controller_API : Dequeue (WORKING-Queue, Count=0) Z-Wave function call 'ZW_AddNodeToNetwork(Mode(s)=[ADD_NODE_ANY, ADD_NODE_OPTION_HIGH_POWER, ADD_NODE_OPTION_NETWORK_WIDE], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:31,729 (Z-Wave): TX_Session_Layer : Executing Z-Wave function call 'ZW_AddNodeToNetwork(Mode(s)=[ADD_NODE_ANY, ADD_NODE_OPTION_HIGH_POWER, ADD_NODE_OPTION_NETWORK_WIDE], CallbackID=0x00)'... DEBUG 2019-05-29 08:15:31,729 (Z-Wave): TX_Session_Layer : Sending Z-Wave function 'ZW_AddNodeToNetwork(Mode(s)=[ADD_NODE_ANY, ADD_NODE_OPTION_HIGH_POWER, ADD_NODE_OPTION_NETWORK_WIDE], CallbackID=0x1C)' call. DEBUG 2019-05-29 08:15:31,729 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x05, 0x00, 0x4A, 0xC1, 0x1C, 0x6D]. DEBUG 2019-05-29 08:15:31,744 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06] DEBUG 2019-05-29 08:15:31,744 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x05, 0x00, 0x4A, 0xC1, 0x1C, 0x6D] transmission OK. DEBUG 2019-05-29 08:15:31,744 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:31,744 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x07, 0x00, 0x4A, 0x1C, 0x01, 0x00, 0x00, 0xAF] DEBUG 2019-05-29 08:15:31,744 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function 'ZW_AddNodeToNetwork(Mode(s)=[ADD_NODE_ANY, ADD_NODE_OPTION_HIGH_POWER, ADD_NODE_OPTION_NETWORK_WIDE], CallbackID=0x1C)' has been successfully sent --> waiting '10 000' [ms] for 'ADD_NODE_STATUS_LEARN_READY' callback. DEBUG 2019-05-29 08:15:31,744 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x07, 0x00, 0x4A, 0x1C, 0x01, 0x00, 0x00, 0xAF] has been received. DEBUG 2019-05-29 08:15:31,760 (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=0x1C)' has received 'ADD_NODE_STATUS_LEARN_READY' callback --> waiting '60 000' [ms] for 'ADD_NODE_STATUS_NODE_FOUND' callback. DEBUG 2019-05-29 08:15:36,447 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:36,447 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x07, 0x00, 0x4A, 0x1C, 0x02, 0x00, 0x00, 0xAC] DEBUG 2019-05-29 08:15:36,447 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x07, 0x00, 0x4A, 0x1C, 0x02, 0x00, 0x00, 0xAC] has been received. DEBUG 2019-05-29 08:15:36,447 (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=0x1C)' has received 'ADD_NODE_STATUS_NODE_FOUND' callback frame [Status: ADD_NODE_STATUS_NODE_FOUND, Callback ID: 0x1C, Node ID: 0, Device Classes: [Basic: 0x00, Generic: 0x00, Specific: 0x00], Command Classes: [Supported: [ -- ], Controlled: [ -- ]]] --> waiting '76 000' [ms] for 'ADD_NODE_STATUS_ADDING_SLAVE' or 'ADD_NODE_STATUS_ADDING_CONTROLLER' callback. DEBUG 2019-05-29 08:15:36,604 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:36,619 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x14, 0x00, 0x4A, 0x1C, 0x03, 0x33, 0x0D, 0x04, 0x20, 0x01, 0x30, 0x60, 0x85, 0x8E, 0x72, 0x70, 0x86, 0x7A, 0xEF, 0x2B, 0xC4] DEBUG 2019-05-29 08:15:36,619 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x14, 0x00, 0x4A, 0x1C, 0x03, 0x33, 0x0D, 0x04, 0x20, 0x01, 0x30, 0x60, 0x85, 0x8E, 0x72, 0x70, 0x86, 0x7A, 0xEF, 0x2B, 0xC4] has been received. DEBUG 2019-05-29 08:15:36,619 (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=0x1C)' has received 'ADD_NODE_STATUS_ADDING_SLAVE' callback frame [Status: ADD_NODE_STATUS_ADDING_SLAVE, Callback ID: 0x1C, Node ID: 51, Device Classes: [Basic: 0x04, Generic: 0x20, Specific: 0x01], Command Classes: [Supported: [COMMAND_CLASS_SENSOR_BINARY, COMMAND_CLASS_MULTI_INSTANCE, COMMAND_CLASS_ASSOCIATION, COMMAND_CLASS_MULTI_INSTANCE_ASSOCIATION, COMMAND_CLASS_MANUFACTURER_SPECIFIC, COMMAND_CLASS_CONFIGURATION, COMMAND_CLASS_VERSION, COMMAND_CLASS_FIRMWARE_UPDATE_MD], Controlled: [COMMAND_CLASS_SCENE_ACTIVATION]]] --> waiting for 'ADD_NODE_STATUS_PROTOCOL_DONE' callback. DEBUG 2019-05-29 08:15:48,072 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:48,072 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x07, 0x00, 0x4A, 0x1C, 0x05, 0x33, 0x00, 0x98] DEBUG 2019-05-29 08:15:48,072 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x07, 0x00, 0x4A, 0x1C, 0x05, 0x33, 0x00, 0x98] has been received. DEBUG 2019-05-29 08:15:48,072 (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=0x1C)' has received 'ADD_NODE_STATUS_PROTOCOL_DONE' callback frame [Status: ADD_NODE_STATUS_PROTOCOL_DONE, Callback ID: 0x1C, Node ID: 51, Device Classes: [Basic: 0x00, Generic: 0x00, Specific: 0x00], Command Classes: [Supported: [ -- ], Controlled: [ -- ]]]. DEBUG 2019-05-29 08:15:48,104 (Z-Wave): TX_Session_Layer : Sending Z-Wave function 'ZW_AddNodeToNetwork(Mode=ADD_NODE_STOP, callback ID: 0x1C)' call. DEBUG 2019-05-29 08:15:48,104 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x05, 0x00, 0x4A, 0x05, 0x1C, 0xA9]. DEBUG 2019-05-29 08:15:48,135 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06] DEBUG 2019-05-29 08:15:48,150 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x05, 0x00, 0x4A, 0x05, 0x1C, 0xA9] transmission OK. DEBUG 2019-05-29 08:15:48,150 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function 'ZW_AddNodeToNetwork(Mode=ADD_NODE_STOP, callback ID: 0x1C)' has been successfully sent --> waiting '500' [ms] for 'ADD_NODE_STATUS_DONE' callback. DEBUG 2019-05-29 08:15:48,197 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:48,197 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x07, 0x00, 0x4A, 0x1C, 0x06, 0x33, 0x00, 0x9B] DEBUG 2019-05-29 08:15:48,197 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x07, 0x00, 0x4A, 0x1C, 0x06, 0x33, 0x00, 0x9B] has been received. DEBUG 2019-05-29 08:15:48,197 (Z-Wave): RX_Session_Layer : Callback received [0x01, 0x07, 0x00, 0x4A, 0x1C, 0x06, 0x33, 0x00, 0x9B] -> Z-Wave function 'ZW_AddNodeToNetwork(Mode=ADD_NODE_STOP, callback ID: 0x1C)' successfully executed. DEBUG 2019-05-29 08:15:48,197 (Z-Wave): TX_Session_Layer : Sending Z-Wave function 'ZW_AddNodeToNetwork(Mode=ADD_NODE_STOP)' call. DEBUG 2019-05-29 08:15:48,197 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x04, 0x00, 0x4A, 0x05, 0xB4]. DEBUG 2019-05-29 08:15:48,213 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06] DEBUG 2019-05-29 08:15:48,213 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x04, 0x00, 0x4A, 0x05, 0xB4] transmission OK. DEBUG 2019-05-29 08:15:48,213 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function 'ZW_AddNodeToNetwork(Mode=ADD_NODE_STOP)' successfully executed. DEBUG 2019-05-29 08:15:48,213 (Z-Wave): Inclusion_Manager : Node '51' : [ZWAddNodeToNetwork, Status=ADD_NODE_STATUS_DONE, Supported=[COMMAND_CLASS_SENSOR_BINARY, COMMAND_CLASS_MULTI_INSTANCE, COMMAND_CLASS_ASSOCIATION, COMMAND_CLASS_MULTI_INSTANCE_ASSOCIATION, COMMAND_CLASS_MANUFACTURER_SPECIFIC, COMMAND_CLASS_CONFIGURATION, COMMAND_CLASS_VERSION, COMMAND_CLASS_FIRMWARE_UPDATE_MD], Controlled=[COMMAND_CLASS_SCENE_ACTIVATION]] INFO 2019-05-29 08:15:48,229 (Z-Wave): Inclusion_Manager : Node '51' : Z-Wave node has been successfully added to the Z-Wave network. DEBUG 2019-05-29 08:15:48,229 (Z-Wave): Controller : Retrieving Z-Wave node info (ID=51)... DEBUG 2019-05-29 08:15:48,229 (Z-Wave): Controller_API : Enqueue (WORKING-Queue, Count=1) Z-Wave function call 'ZW_GetNodeProtocolInfo(NodeID=51)'. DEBUG 2019-05-29 08:15:48,229 (Z-Wave): Controller_API : Dequeue (WORKING-Queue, Count=0) Z-Wave function call 'ZW_GetNodeProtocolInfo(NodeID=51)'. DEBUG 2019-05-29 08:15:48,229 (Z-Wave): TX_Session_Layer : Executing Z-Wave function call 'ZW_GetNodeProtocolInfo(NodeID=51)'... DEBUG 2019-05-29 08:15:48,229 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x04, 0x00, 0x41, 0x33, 0x89]. DEBUG 2019-05-29 08:15:48,244 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06] DEBUG 2019-05-29 08:15:48,244 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x04, 0x00, 0x41, 0x33, 0x89] transmission OK. DEBUG 2019-05-29 08:15:48,244 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01, 0x09, 0x01, 0x41, 0xD3, 0x9C, 0x00, 0x04, 0x20, 0x01, 0xDC] DEBUG 2019-05-29 08:15:48,244 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function 'ZW_GetNodeProtocolInfo(NodeID=51)' has been successfully sent - waiting 5 000 [ms] for response frame. DEBUG 2019-05-29 08:15:48,244 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x09, 0x01, 0x41, 0xD3, 0x9C, 0x00, 0x04, 0x20, 0x01, 0xDC] has been received. DEBUG 2019-05-29 08:15:48,244 (Z-Wave): RX_Session_Layer : Response received [0x01, 0x09, 0x01, 0x41, 0xD3, 0x9C, 0x00, 0x04, 0x20, 0x01, 0xDC] -> Z-Wave function 'ZW_GetNodeProtocolInfo(NodeID=51)' successfully executed. DEBUG 2019-05-29 08:15:48,260 (Z-Wave): Node_Initializer : Node '51' : [ZW_RequestNodeInfo, (Retry='1')] DEBUG 2019-05-29 08:15:48,260 (Z-Wave): Controller_API : Enqueue (WORKING-Queue, Count=1) Z-Wave function call 'ZW_RequestNodeInfo(NodeID=51)'. INFO 2019-05-29 08:15:48,260 (Z-Wave): Controller : Z-Wave node info (ID=51) : [[Device Classes : 'BASIC_TYPE_ROUTING_SLAVE','GENERIC_TYPE_SENSOR_BINARY','SPECIFIC_TYPE_ROUTING_SENSOR_BINARY'],[Capabilities : 'NODEINFO_CAPABILITY_ROUTING','NODEINFO_CAPABILITY_LISTENING'],[Security : 'NODEINFO_SECURITY_OPTIONAL_FUNC_SUPPORT']]. DEBUG 2019-05-29 08:15:48,275 (Z-Wave): Controller_API : Dequeue (WORKING-Queue, Count=0) Z-Wave function call 'ZW_RequestNodeInfo(NodeID=51)'. DEBUG 2019-05-29 08:15:48,338 (Z-Wave): TX_Session_Layer : Executing Z-Wave function call 'ZW_RequestNodeInfo(NodeID=51)'... DEBUG 2019-05-29 08:15:48,338 (Z-Wave): ZW_RequestNodeInfo : Sending Z-Wave function 'ZW_RequestNodeInfo(NodeID=51)' call. DEBUG 2019-05-29 08:15:48,338 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x04, 0x00, 0x60, 0x33, 0xA8]. DEBUG 2019-05-29 08:15:48,275 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:48,354 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x07, 0x00, 0x4A, 0x1C, 0x06, 0x33, 0x00, 0x9B] DEBUG 2019-05-29 08:15:48,354 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x18] DEBUG 2019-05-29 08:15:48,354 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x07, 0x00, 0x4A, 0x1C, 0x06, 0x33, 0x00, 0x9B] has been received. DEBUG 2019-05-29 08:15:48,354 (Z-Wave): RX_Session_Layer : Received an unexpected frame [0x01, 0x07, 0x00, 0x4A, 0x1C, 0x06, 0x33, 0x00, 0x9B] while waiting for an ACK of the Z-Wave function 'ZW_RequestNodeInfo(NodeID=51)'. DEBUG 2019-05-29 08:15:48,354 (Z-Wave): RX_Frame_Layer : CAN -> Failed to send data frame [0x01, 0x04, 0x00, 0x60, 0x33, 0xA8] because the Z-Wave firmware has an ACK expected instead of the sent frame DEBUG 2019-05-29 08:15:48,354 (Z-Wave): TX_Frame_Layer : CAN -> Wait 100 [ms] before next retransmission attempt. DEBUG 2019-05-29 08:15:48,479 (Z-Wave): TX_Frame_Layer : Retransmission attempt 1, data frame [0x01, 0x04, 0x00, 0x60, 0x33, 0xA8] DEBUG 2019-05-29 08:15:48,479 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06] DEBUG 2019-05-29 08:15:48,479 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x04, 0x00, 0x60, 0x33, 0xA8] transmission OK. DEBUG 2019-05-29 08:15:48,479 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function 'ZW_RequestNodeInfo(NodeID=51)' has been successfully sent - waiting 5 000 [ms] for response frame. DEBUG 2019-05-29 08:15:48,510 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:48,510 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x04, 0x01, 0x60, 0x01, 0x9B] DEBUG 2019-05-29 08:15:48,510 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x04, 0x01, 0x60, 0x01, 0x9B] has been received. DEBUG 2019-05-29 08:15:48,510 (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=51)'. DEBUG 2019-05-29 08:15:48,604 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:48,604 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x13, 0x00, 0x49, 0x84, 0x33, 0x0D, 0x04, 0x20, 0x01, 0x30, 0x60, 0x85, 0x8E, 0x72, 0x70, 0x86, 0x7A, 0xEF, 0x2B, 0x5B] DEBUG 2019-05-29 08:15:48,604 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x13, 0x00, 0x49, 0x84, 0x33, 0x0D, 0x04, 0x20, 0x01, 0x30, 0x60, 0x85, 0x8E, 0x72, 0x70, 0x86, 0x7A, 0xEF, 0x2B, 0x5B] has been received. DEBUG 2019-05-29 08:15:48,604 (Z-Wave): RX_Session_Layer : Callback received [0x01, 0x13, 0x00, 0x49, 0x84, 0x33, 0x0D, 0x04, 0x20, 0x01, 0x30, 0x60, 0x85, 0x8E, 0x72, 0x70, 0x86, 0x7A, 0xEF, 0x2B, 0x5B] -> Z-Wave function 'ZW_RequestNodeInfo(NodeID=51)' successfully executed. DEBUG 2019-05-29 08:15:48,604 (Z-Wave): Node_Initializer : Node '51' : [ZW_RequestNodeInfo, (Retry='1')] succeeded : [[Status: UPDATE_STATE_NODE_INFO_RECEIVED, Node ID: 51, Device Classes: [Basic: BASIC_TYPE_ROUTING_SLAVE, Generic: GENERIC_TYPE_SENSOR_BINARY, Specific: SPECIFIC_TYPE_ROUTING_SENSOR_BINARY], Command Classes: [Supported: [COMMAND_CLASS_SENSOR_BINARY, COMMAND_CLASS_MULTI_INSTANCE, COMMAND_CLASS_ASSOCIATION, COMMAND_CLASS_MULTI_INSTANCE_ASSOCIATION, COMMAND_CLASS_MANUFACTURER_SPECIFIC, COMMAND_CLASS_CONFIGURATION, COMMAND_CLASS_VERSION, COMMAND_CLASS_FIRMWARE_UPDATE_MD], Controlled: [COMMAND_CLASS_SCENE_ACTIVATION]]]]. DEBUG 2019-05-29 08:15:48,619 (Z-Wave): Node_Initializer : Node '51' : [ZW_GetNodeProtocolInfo]... DEBUG 2019-05-29 08:15:48,619 (Z-Wave): Controller_API : Enqueue (WORKING-Queue, Count=1) Z-Wave function call 'ZW_GetNodeProtocolInfo(NodeID=51)'. DEBUG 2019-05-29 08:15:48,619 (Z-Wave): Controller_API : Dequeue (WORKING-Queue, Count=0) Z-Wave function call 'ZW_GetNodeProtocolInfo(NodeID=51)'. DEBUG 2019-05-29 08:15:48,619 (Z-Wave): TX_Session_Layer : Executing Z-Wave function call 'ZW_GetNodeProtocolInfo(NodeID=51)'... DEBUG 2019-05-29 08:15:48,619 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x04, 0x00, 0x41, 0x33, 0x89]. DEBUG 2019-05-29 08:15:48,619 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06] DEBUG 2019-05-29 08:15:48,619 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x04, 0x00, 0x41, 0x33, 0x89] transmission OK. DEBUG 2019-05-29 08:15:48,619 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function 'ZW_GetNodeProtocolInfo(NodeID=51)' has been successfully sent - waiting 5 000 [ms] for response frame. DEBUG 2019-05-29 08:15:48,619 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:48,619 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x09, 0x01, 0x41, 0xD3, 0x9C, 0x00, 0x04, 0x20, 0x01, 0xDC] DEBUG 2019-05-29 08:15:48,619 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x09, 0x01, 0x41, 0xD3, 0x9C, 0x00, 0x04, 0x20, 0x01, 0xDC] has been received. DEBUG 2019-05-29 08:15:48,619 (Z-Wave): RX_Session_Layer : Response received [0x01, 0x09, 0x01, 0x41, 0xD3, 0x9C, 0x00, 0x04, 0x20, 0x01, 0xDC] -> Z-Wave function 'ZW_GetNodeProtocolInfo(NodeID=51)' successfully executed. DEBUG 2019-05-29 08:15:48,635 (Z-Wave): Node_Initializer : Node '51' : [ZW_GetNodeProtocolInfo] : [[Device Classes : 'BASIC_TYPE_ROUTING_SLAVE','GENERIC_TYPE_SENSOR_BINARY','SPECIFIC_TYPE_ROUTING_SENSOR_BINARY'],[Capabilities : 'NODEINFO_CAPABILITY_ROUTING','NODEINFO_CAPABILITY_LISTENING'],[Security : 'NODEINFO_SECURITY_OPTIONAL_FUNC_SUPPORT']]. DEBUG 2019-05-29 08:15:48,635 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_VERSION::VERSION_COMMAND_CLASS_GET (Retry='1'), CommandClass='COMMAND_CLASS_SENSOR_BINARY']... DEBUG 2019-05-29 08:15:48,650 (Z-Wave): Controller_API : Enqueue (WORKING-Queue, Count=1) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x30], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:48,650 (Z-Wave): Controller_API : Dequeue (WORKING-Queue, Count=0) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x30], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:48,650 (Z-Wave): TX_Session_Layer : Executing Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x30], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'... DEBUG 2019-05-29 08:15:48,650 (Z-Wave): TX_Session_Layer : Send (repeat count=1) Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x30], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x1D)' request (callback ID=0x1D). DEBUG 2019-05-29 08:15:48,650 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x0A, 0x00, 0x13, 0x33, 0x03, 0x86, 0x13, 0x30, 0x05, 0x1D, 0x6B]. DEBUG 2019-05-29 08:15:48,666 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06] DEBUG 2019-05-29 08:15:48,666 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x0A, 0x00, 0x13, 0x33, 0x03, 0x86, 0x13, 0x30, 0x05, 0x1D, 0x6B] transmission OK. DEBUG 2019-05-29 08:15:48,666 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x30], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x1D)' has been successfully sent - waiting 5 000 [ms] for response frame. DEBUG 2019-05-29 08:15:48,666 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:48,666 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x04, 0x01, 0x13, 0x01, 0xE8] DEBUG 2019-05-29 08:15:48,666 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] has been received. DEBUG 2019-05-29 08:15:48,666 (Z-Wave): RX_Session_Layer : 'ZW_SendData' response [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] with status 'RETURN_VALUE_TRUE' received (callback ID=0x1D). DEBUG 2019-05-29 08:15:48,666 (Z-Wave): RX_Session_Layer : Waiting 64 982 [ms] for 'ZW_SendData' callback frame (callback ID=0x1D). DEBUG 2019-05-29 08:15:48,713 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:48,713 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x05, 0x00, 0x13, 0x1D, 0x00, 0xF4] DEBUG 2019-05-29 08:15:48,713 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x05, 0x00, 0x13, 0x1D, 0x00, 0xF4] has been received. DEBUG 2019-05-29 08:15:48,713 (Z-Wave): RX_Session_Layer : Callback [0x01, 0x05, 0x00, 0x13, 0x1D, 0x00, 0xF4] (callback ID=0x1D) with state 'TRANSMIT_COMPLETE_OK' received -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x30], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x1D)' successfully executed. DEBUG 2019-05-29 08:15:48,713 (Z-Wave): RX_Session_Layer : Add function to pending transaction list (size='1') : ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x30], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x1D) DEBUG 2019-05-29 08:15:48,744 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:48,760 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x0A, 0x00, 0x04, 0x00, 0x33, 0x04, 0x86, 0x14, 0x30, 0x01, 0x65] DEBUG 2019-05-29 08:15:48,760 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x0A, 0x00, 0x04, 0x00, 0x33, 0x04, 0x86, 0x14, 0x30, 0x01, 0x65] has been received. DEBUG 2019-05-29 08:15:48,760 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_VERSION::VERSION_COMMAND_CLASS_REPORT (Retry='1'), CommandClass='COMMAND_CLASS_SENSOR_BINARY', Version='1']. DEBUG 2019-05-29 08:15:48,760 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_VERSION::VERSION_COMMAND_CLASS_GET (Retry='1'), CommandClass='COMMAND_CLASS_MULTI_INSTANCE']... DEBUG 2019-05-29 08:15:48,760 (Z-Wave): Controller_API : Enqueue (WORKING-Queue, Count=1) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x60], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:48,760 (Z-Wave): RX_Session_Layer : Removed function from pending transaction list (size='0') : ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x30], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x1D) DEBUG 2019-05-29 08:15:48,760 (Z-Wave): Controller_API : Dequeue (WORKING-Queue, Count=0) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x60], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:48,760 (Z-Wave): TX_Session_Layer : Executing Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x60], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'... DEBUG 2019-05-29 08:15:48,760 (Z-Wave): TX_Session_Layer : Send (repeat count=1) Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x60], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x1E)' request (callback ID=0x1E). DEBUG 2019-05-29 08:15:48,760 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x0A, 0x00, 0x13, 0x33, 0x03, 0x86, 0x13, 0x60, 0x05, 0x1E, 0x38]. DEBUG 2019-05-29 08:15:48,775 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06] DEBUG 2019-05-29 08:15:48,775 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x0A, 0x00, 0x13, 0x33, 0x03, 0x86, 0x13, 0x60, 0x05, 0x1E, 0x38] transmission OK. DEBUG 2019-05-29 08:15:48,775 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x60], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x1E)' has been successfully sent - waiting 5 000 [ms] for response frame. DEBUG 2019-05-29 08:15:48,775 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:48,775 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x04, 0x01, 0x13, 0x01, 0xE8] DEBUG 2019-05-29 08:15:48,775 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] has been received. DEBUG 2019-05-29 08:15:48,775 (Z-Wave): RX_Session_Layer : 'ZW_SendData' response [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] with status 'RETURN_VALUE_TRUE' received (callback ID=0x1E). DEBUG 2019-05-29 08:15:48,775 (Z-Wave): RX_Session_Layer : Waiting 64 981 [ms] for 'ZW_SendData' callback frame (callback ID=0x1E). DEBUG 2019-05-29 08:15:48,838 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:48,838 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x05, 0x00, 0x13, 0x1E, 0x00, 0xF7] DEBUG 2019-05-29 08:15:48,838 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x05, 0x00, 0x13, 0x1E, 0x00, 0xF7] has been received. DEBUG 2019-05-29 08:15:48,838 (Z-Wave): RX_Session_Layer : Callback [0x01, 0x05, 0x00, 0x13, 0x1E, 0x00, 0xF7] (callback ID=0x1E) with state 'TRANSMIT_COMPLETE_OK' received -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x60], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x1E)' successfully executed. DEBUG 2019-05-29 08:15:48,838 (Z-Wave): RX_Session_Layer : Add function to pending transaction list (size='1') : ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x60], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x1E) DEBUG 2019-05-29 08:15:48,885 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:48,885 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x0A, 0x00, 0x04, 0x00, 0x33, 0x04, 0x86, 0x14, 0x60, 0x02, 0x36] DEBUG 2019-05-29 08:15:48,885 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x0A, 0x00, 0x04, 0x00, 0x33, 0x04, 0x86, 0x14, 0x60, 0x02, 0x36] has been received. DEBUG 2019-05-29 08:15:48,885 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_VERSION::VERSION_COMMAND_CLASS_REPORT (Retry='1'), CommandClass='COMMAND_CLASS_MULTI_INSTANCE', Version='2']. DEBUG 2019-05-29 08:15:48,947 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_VERSION::VERSION_COMMAND_CLASS_GET (Retry='1'), CommandClass='COMMAND_CLASS_ASSOCIATION']... DEBUG 2019-05-29 08:15:48,947 (Z-Wave): Controller_API : Enqueue (WORKING-Queue, Count=1) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x85], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:48,947 (Z-Wave): RX_Session_Layer : Removed function from pending transaction list (size='0') : ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x60], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x1E) DEBUG 2019-05-29 08:15:48,947 (Z-Wave): Controller_API : Dequeue (WORKING-Queue, Count=0) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x85], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:48,947 (Z-Wave): TX_Session_Layer : Executing Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x85], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'... DEBUG 2019-05-29 08:15:48,947 (Z-Wave): TX_Session_Layer : Send (repeat count=1) Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x85], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x1F)' request (callback ID=0x1F). DEBUG 2019-05-29 08:15:48,947 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x0A, 0x00, 0x13, 0x33, 0x03, 0x86, 0x13, 0x85, 0x05, 0x1F, 0xDC]. DEBUG 2019-05-29 08:15:48,963 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06] DEBUG 2019-05-29 08:15:48,963 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x0A, 0x00, 0x13, 0x33, 0x03, 0x86, 0x13, 0x85, 0x05, 0x1F, 0xDC] transmission OK. DEBUG 2019-05-29 08:15:48,963 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x85], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x1F)' has been successfully sent - waiting 5 000 [ms] for response frame. DEBUG 2019-05-29 08:15:48,963 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] DEBUG 2019-05-29 08:15:48,963 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] has been received. DEBUG 2019-05-29 08:15:48,963 (Z-Wave): RX_Session_Layer : 'ZW_SendData' response [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] with status 'RETURN_VALUE_TRUE' received (callback ID=0x1F). DEBUG 2019-05-29 08:15:48,963 (Z-Wave): RX_Session_Layer : Waiting 64 978 [ms] for 'ZW_SendData' callback frame (callback ID=0x1F). DEBUG 2019-05-29 08:15:49,010 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:49,010 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x05, 0x00, 0x13, 0x1F, 0x00, 0xF6] DEBUG 2019-05-29 08:15:49,010 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x05, 0x00, 0x13, 0x1F, 0x00, 0xF6] has been received. DEBUG 2019-05-29 08:15:49,010 (Z-Wave): RX_Session_Layer : Callback [0x01, 0x05, 0x00, 0x13, 0x1F, 0x00, 0xF6] (callback ID=0x1F) with state 'TRANSMIT_COMPLETE_OK' received -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x85], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x1F)' successfully executed. DEBUG 2019-05-29 08:15:49,025 (Z-Wave): RX_Session_Layer : Add function to pending transaction list (size='1') : ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x85], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x1F) DEBUG 2019-05-29 08:15:49,041 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:49,041 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x0A, 0x00, 0x04, 0x00, 0x33, 0x04, 0x86, 0x14, 0x85, 0x02, 0xD3] DEBUG 2019-05-29 08:15:49,041 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x0A, 0x00, 0x04, 0x00, 0x33, 0x04, 0x86, 0x14, 0x85, 0x02, 0xD3] has been received. DEBUG 2019-05-29 08:15:49,041 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_VERSION::VERSION_COMMAND_CLASS_REPORT (Retry='1'), CommandClass='COMMAND_CLASS_ASSOCIATION', Version='2']. DEBUG 2019-05-29 08:15:49,041 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_VERSION::VERSION_COMMAND_CLASS_GET (Retry='1'), CommandClass='COMMAND_CLASS_MULTI_INSTANCE_ASSOCIATION']... DEBUG 2019-05-29 08:15:49,041 (Z-Wave): Controller_API : Enqueue (WORKING-Queue, Count=1) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x8E], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:49,057 (Z-Wave): RX_Session_Layer : Removed function from pending transaction list (size='0') : ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x85], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x1F) DEBUG 2019-05-29 08:15:49,057 (Z-Wave): Controller_API : Dequeue (WORKING-Queue, Count=0) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x8E], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:49,057 (Z-Wave): TX_Session_Layer : Executing Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x8E], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'... DEBUG 2019-05-29 08:15:49,057 (Z-Wave): TX_Session_Layer : Send (repeat count=1) Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x8E], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x20)' request (callback ID=0x20). DEBUG 2019-05-29 08:15:49,057 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x0A, 0x00, 0x13, 0x33, 0x03, 0x86, 0x13, 0x8E, 0x05, 0x20, 0xE8]. DEBUG 2019-05-29 08:15:49,057 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06] DEBUG 2019-05-29 08:15:49,057 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x0A, 0x00, 0x13, 0x33, 0x03, 0x86, 0x13, 0x8E, 0x05, 0x20, 0xE8] transmission OK. DEBUG 2019-05-29 08:15:49,057 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x8E], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x20)' has been successfully sent - waiting 5 000 [ms] for response frame. DEBUG 2019-05-29 08:15:49,072 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:49,072 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x04, 0x01, 0x13, 0x01, 0xE8] DEBUG 2019-05-29 08:15:49,072 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] has been received. DEBUG 2019-05-29 08:15:49,072 (Z-Wave): RX_Session_Layer : 'ZW_SendData' response [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] with status 'RETURN_VALUE_TRUE' received (callback ID=0x20). DEBUG 2019-05-29 08:15:49,072 (Z-Wave): RX_Session_Layer : Waiting 64 983 [ms] for 'ZW_SendData' callback frame (callback ID=0x20). DEBUG 2019-05-29 08:15:49,135 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:49,135 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x05, 0x00, 0x13, 0x20, 0x00, 0xC9] DEBUG 2019-05-29 08:15:49,135 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x05, 0x00, 0x13, 0x20, 0x00, 0xC9] has been received. DEBUG 2019-05-29 08:15:49,135 (Z-Wave): RX_Session_Layer : Callback [0x01, 0x05, 0x00, 0x13, 0x20, 0x00, 0xC9] (callback ID=0x20) with state 'TRANSMIT_COMPLETE_OK' received -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x8E], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x20)' successfully executed. DEBUG 2019-05-29 08:15:49,135 (Z-Wave): RX_Session_Layer : Add function to pending transaction list (size='1') : ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x8E], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x20) DEBUG 2019-05-29 08:15:49,182 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:49,182 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x0A, 0x00, 0x04, 0x00, 0x33, 0x04, 0x86, 0x14, 0x8E, 0x02, 0xD8] DEBUG 2019-05-29 08:15:49,182 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x0A, 0x00, 0x04, 0x00, 0x33, 0x04, 0x86, 0x14, 0x8E, 0x02, 0xD8] has been received. DEBUG 2019-05-29 08:15:49,182 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_VERSION::VERSION_COMMAND_CLASS_REPORT (Retry='1'), CommandClass='COMMAND_CLASS_MULTI_INSTANCE_ASSOCIATION', Version='2']. DEBUG 2019-05-29 08:15:49,182 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_VERSION::VERSION_COMMAND_CLASS_GET (Retry='1'), CommandClass='COMMAND_CLASS_MANUFACTURER_SPECIFIC']... DEBUG 2019-05-29 08:15:49,182 (Z-Wave): Controller_API : Enqueue (WORKING-Queue, Count=1) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x72], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:49,182 (Z-Wave): Controller_API : Dequeue (WORKING-Queue, Count=0) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x72], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:49,182 (Z-Wave): RX_Session_Layer : Removed function from pending transaction list (size='0') : ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x8E], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x20) DEBUG 2019-05-29 08:15:49,182 (Z-Wave): TX_Session_Layer : Executing Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x72], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'... DEBUG 2019-05-29 08:15:49,182 (Z-Wave): TX_Session_Layer : Send (repeat count=1) Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x72], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x21)' request (callback ID=0x21). DEBUG 2019-05-29 08:15:49,182 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x0A, 0x00, 0x13, 0x33, 0x03, 0x86, 0x13, 0x72, 0x05, 0x21, 0x15]. DEBUG 2019-05-29 08:15:49,197 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06] DEBUG 2019-05-29 08:15:49,197 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x0A, 0x00, 0x13, 0x33, 0x03, 0x86, 0x13, 0x72, 0x05, 0x21, 0x15] transmission OK. DEBUG 2019-05-29 08:15:49,197 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x72], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x21)' has been successfully sent - waiting 5 000 [ms] for response frame. DEBUG 2019-05-29 08:15:49,197 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:49,197 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x04, 0x01, 0x13, 0x01, 0xE8] DEBUG 2019-05-29 08:15:49,197 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] has been received. DEBUG 2019-05-29 08:15:49,197 (Z-Wave): RX_Session_Layer : 'ZW_SendData' response [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] with status 'RETURN_VALUE_TRUE' received (callback ID=0x21). DEBUG 2019-05-29 08:15:49,197 (Z-Wave): RX_Session_Layer : Waiting 64 982 [ms] for 'ZW_SendData' callback frame (callback ID=0x21). DEBUG 2019-05-29 08:15:49,275 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:49,275 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x05, 0x00, 0x13, 0x21, 0x00, 0xC8] DEBUG 2019-05-29 08:15:49,275 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x05, 0x00, 0x13, 0x21, 0x00, 0xC8] has been received. DEBUG 2019-05-29 08:15:49,275 (Z-Wave): RX_Session_Layer : Callback [0x01, 0x05, 0x00, 0x13, 0x21, 0x00, 0xC8] (callback ID=0x21) with state 'TRANSMIT_COMPLETE_OK' received -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x72], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x21)' successfully executed. DEBUG 2019-05-29 08:15:49,275 (Z-Wave): RX_Session_Layer : Add function to pending transaction list (size='1') : ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x72], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x21) DEBUG 2019-05-29 08:15:49,307 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:49,322 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x0A, 0x00, 0x04, 0x00, 0x33, 0x04, 0x86, 0x14, 0x72, 0x01, 0x27] DEBUG 2019-05-29 08:15:49,322 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x0A, 0x00, 0x04, 0x00, 0x33, 0x04, 0x86, 0x14, 0x72, 0x01, 0x27] has been received. DEBUG 2019-05-29 08:15:49,322 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_VERSION::VERSION_COMMAND_CLASS_REPORT (Retry='1'), CommandClass='COMMAND_CLASS_MANUFACTURER_SPECIFIC', Version='1']. DEBUG 2019-05-29 08:15:49,322 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_VERSION::VERSION_COMMAND_CLASS_GET (Retry='1'), CommandClass='COMMAND_CLASS_CONFIGURATION']... DEBUG 2019-05-29 08:15:49,338 (Z-Wave): Controller_API : Enqueue (WORKING-Queue, Count=1) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x70], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:49,338 (Z-Wave): RX_Session_Layer : Removed function from pending transaction list (size='0') : ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x72], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x21) DEBUG 2019-05-29 08:15:49,338 (Z-Wave): Controller_API : Dequeue (WORKING-Queue, Count=0) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x70], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:49,338 (Z-Wave): TX_Session_Layer : Executing Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x70], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'... DEBUG 2019-05-29 08:15:49,338 (Z-Wave): TX_Session_Layer : Send (repeat count=1) Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x70], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x22)' request (callback ID=0x22). DEBUG 2019-05-29 08:15:49,338 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x0A, 0x00, 0x13, 0x33, 0x03, 0x86, 0x13, 0x70, 0x05, 0x22, 0x14]. DEBUG 2019-05-29 08:15:49,354 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06] DEBUG 2019-05-29 08:15:49,354 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x0A, 0x00, 0x13, 0x33, 0x03, 0x86, 0x13, 0x70, 0x05, 0x22, 0x14] transmission OK. DEBUG 2019-05-29 08:15:49,354 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] DEBUG 2019-05-29 08:15:49,354 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x70], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x22)' has been successfully sent - waiting 5 000 [ms] for response frame. DEBUG 2019-05-29 08:15:49,354 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] has been received. DEBUG 2019-05-29 08:15:49,354 (Z-Wave): RX_Session_Layer : 'ZW_SendData' response [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] with status 'RETURN_VALUE_TRUE' received (callback ID=0x22). DEBUG 2019-05-29 08:15:49,354 (Z-Wave): RX_Session_Layer : Waiting 64 974 [ms] for 'ZW_SendData' callback frame (callback ID=0x22). DEBUG 2019-05-29 08:15:49,400 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:49,416 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x05, 0x00, 0x13, 0x22, 0x00, 0xCB] DEBUG 2019-05-29 08:15:49,416 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x05, 0x00, 0x13, 0x22, 0x00, 0xCB] has been received. DEBUG 2019-05-29 08:15:49,416 (Z-Wave): RX_Session_Layer : Callback [0x01, 0x05, 0x00, 0x13, 0x22, 0x00, 0xCB] (callback ID=0x22) with state 'TRANSMIT_COMPLETE_OK' received -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x70], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x22)' successfully executed. DEBUG 2019-05-29 08:15:49,416 (Z-Wave): RX_Session_Layer : Add function to pending transaction list (size='1') : ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x70], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x22) DEBUG 2019-05-29 08:15:49,447 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:49,447 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x0A, 0x00, 0x04, 0x00, 0x33, 0x04, 0x86, 0x14, 0x70, 0x01, 0x25] DEBUG 2019-05-29 08:15:49,447 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x0A, 0x00, 0x04, 0x00, 0x33, 0x04, 0x86, 0x14, 0x70, 0x01, 0x25] has been received. DEBUG 2019-05-29 08:15:49,463 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_VERSION::VERSION_COMMAND_CLASS_REPORT (Retry='1'), CommandClass='COMMAND_CLASS_CONFIGURATION', Version='1']. DEBUG 2019-05-29 08:15:49,463 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_VERSION::VERSION_COMMAND_CLASS_GET (Retry='1'), CommandClass='COMMAND_CLASS_VERSION']... DEBUG 2019-05-29 08:15:49,463 (Z-Wave): Controller_API : Enqueue (WORKING-Queue, Count=1) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x86], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:49,463 (Z-Wave): RX_Session_Layer : Removed function from pending transaction list (size='0') : ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x70], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x22) DEBUG 2019-05-29 08:15:49,463 (Z-Wave): Controller_API : Dequeue (WORKING-Queue, Count=0) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x86], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:49,463 (Z-Wave): TX_Session_Layer : Executing Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x86], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'... DEBUG 2019-05-29 08:15:49,463 (Z-Wave): TX_Session_Layer : Send (repeat count=1) Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x86], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x23)' request (callback ID=0x23). DEBUG 2019-05-29 08:15:49,463 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x0A, 0x00, 0x13, 0x33, 0x03, 0x86, 0x13, 0x86, 0x05, 0x23, 0xE3]. DEBUG 2019-05-29 08:15:49,479 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06] DEBUG 2019-05-29 08:15:49,479 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x0A, 0x00, 0x13, 0x33, 0x03, 0x86, 0x13, 0x86, 0x05, 0x23, 0xE3] transmission OK. DEBUG 2019-05-29 08:15:49,479 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] DEBUG 2019-05-29 08:15:49,479 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x86], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x23)' has been successfully sent - waiting 5 000 [ms] for response frame. DEBUG 2019-05-29 08:15:49,479 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] has been received. DEBUG 2019-05-29 08:15:49,479 (Z-Wave): RX_Session_Layer : 'ZW_SendData' response [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] with status 'RETURN_VALUE_TRUE' received (callback ID=0x23). DEBUG 2019-05-29 08:15:49,479 (Z-Wave): RX_Session_Layer : Waiting 64 973 [ms] for 'ZW_SendData' callback frame (callback ID=0x23). DEBUG 2019-05-29 08:15:49,541 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:49,541 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x05, 0x00, 0x13, 0x23, 0x00, 0xCA] DEBUG 2019-05-29 08:15:49,557 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x05, 0x00, 0x13, 0x23, 0x00, 0xCA] has been received. DEBUG 2019-05-29 08:15:49,557 (Z-Wave): RX_Session_Layer : Callback [0x01, 0x05, 0x00, 0x13, 0x23, 0x00, 0xCA] (callback ID=0x23) with state 'TRANSMIT_COMPLETE_OK' received -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x86], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x23)' successfully executed. DEBUG 2019-05-29 08:15:49,588 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:49,588 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x0A, 0x00, 0x04, 0x00, 0x33, 0x04, 0x86, 0x14, 0x86, 0x01, 0xD3] DEBUG 2019-05-29 08:15:49,588 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x0A, 0x00, 0x04, 0x00, 0x33, 0x04, 0x86, 0x14, 0x86, 0x01, 0xD3] has been received. DEBUG 2019-05-29 08:15:49,666 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_VERSION::VERSION_COMMAND_CLASS_REPORT (Retry='1'), CommandClass='COMMAND_CLASS_VERSION', Version='1']. DEBUG 2019-05-29 08:15:49,666 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_VERSION::VERSION_COMMAND_CLASS_GET (Retry='1'), CommandClass='COMMAND_CLASS_BASIC']... DEBUG 2019-05-29 08:15:49,666 (Z-Wave): Controller_API : Enqueue (WORKING-Queue, Count=1) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x20], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:49,682 (Z-Wave): Controller_API : Dequeue (WORKING-Queue, Count=0) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x20], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:49,682 (Z-Wave): TX_Session_Layer : Executing Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x20], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'... DEBUG 2019-05-29 08:15:49,682 (Z-Wave): TX_Session_Layer : Send (repeat count=1) Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x20], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x24)' request (callback ID=0x24). DEBUG 2019-05-29 08:15:49,682 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x0A, 0x00, 0x13, 0x33, 0x03, 0x86, 0x13, 0x20, 0x05, 0x24, 0x42]. DEBUG 2019-05-29 08:15:49,713 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06] DEBUG 2019-05-29 08:15:49,713 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x0A, 0x00, 0x13, 0x33, 0x03, 0x86, 0x13, 0x20, 0x05, 0x24, 0x42] transmission OK. DEBUG 2019-05-29 08:15:49,713 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x20], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x24)' has been successfully sent - waiting 5 000 [ms] for response frame. DEBUG 2019-05-29 08:15:49,713 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:49,713 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x04, 0x01, 0x13, 0x01, 0xE8] DEBUG 2019-05-29 08:15:49,713 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] has been received. DEBUG 2019-05-29 08:15:49,713 (Z-Wave): RX_Session_Layer : 'ZW_SendData' response [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] with status 'RETURN_VALUE_TRUE' received (callback ID=0x24). DEBUG 2019-05-29 08:15:49,713 (Z-Wave): RX_Session_Layer : Waiting 64 974 [ms] for 'ZW_SendData' callback frame (callback ID=0x24). DEBUG 2019-05-29 08:15:49,744 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:49,760 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x05, 0x00, 0x13, 0x24, 0x00, 0xCD] DEBUG 2019-05-29 08:15:49,760 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x05, 0x00, 0x13, 0x24, 0x00, 0xCD] has been received. DEBUG 2019-05-29 08:15:49,760 (Z-Wave): RX_Session_Layer : Callback [0x01, 0x05, 0x00, 0x13, 0x24, 0x00, 0xCD] (callback ID=0x24) with state 'TRANSMIT_COMPLETE_OK' received -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x20], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x24)' successfully executed. DEBUG 2019-05-29 08:15:49,760 (Z-Wave): RX_Session_Layer : Add function to pending transaction list (size='1') : ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x20], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x24) DEBUG 2019-05-29 08:15:49,791 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:49,791 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x0A, 0x00, 0x04, 0x00, 0x33, 0x04, 0x86, 0x14, 0x20, 0x01, 0x75] DEBUG 2019-05-29 08:15:49,791 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x0A, 0x00, 0x04, 0x00, 0x33, 0x04, 0x86, 0x14, 0x20, 0x01, 0x75] has been received. DEBUG 2019-05-29 08:15:49,791 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_VERSION::VERSION_COMMAND_CLASS_REPORT (Retry='1'), CommandClass='COMMAND_CLASS_BASIC', Version='1']. DEBUG 2019-05-29 08:15:49,791 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_VERSION::VERSION_COMMAND_CLASS_GET (Retry='1'), CommandClass='COMMAND_CLASS_SCENE_ACTIVATION']... DEBUG 2019-05-29 08:15:49,791 (Z-Wave): Controller_API : Enqueue (WORKING-Queue, Count=1) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x2B], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:49,807 (Z-Wave): RX_Session_Layer : Removed function from pending transaction list (size='0') : ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x20], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x24) DEBUG 2019-05-29 08:15:49,807 (Z-Wave): Controller_API : Dequeue (WORKING-Queue, Count=0) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x2B], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:49,807 (Z-Wave): TX_Session_Layer : Executing Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x2B], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'... DEBUG 2019-05-29 08:15:49,807 (Z-Wave): TX_Session_Layer : Send (repeat count=1) Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x2B], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x25)' request (callback ID=0x25). DEBUG 2019-05-29 08:15:49,807 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x0A, 0x00, 0x13, 0x33, 0x03, 0x86, 0x13, 0x2B, 0x05, 0x25, 0x48]. DEBUG 2019-05-29 08:15:49,807 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06] DEBUG 2019-05-29 08:15:49,822 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x0A, 0x00, 0x13, 0x33, 0x03, 0x86, 0x13, 0x2B, 0x05, 0x25, 0x48] transmission OK. DEBUG 2019-05-29 08:15:49,822 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x2B], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x25)' has been successfully sent - waiting 5 000 [ms] for response frame. DEBUG 2019-05-29 08:15:49,822 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:49,822 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x04, 0x01, 0x13, 0x01, 0xE8] DEBUG 2019-05-29 08:15:49,822 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] has been received. DEBUG 2019-05-29 08:15:49,822 (Z-Wave): RX_Session_Layer : 'ZW_SendData' response [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] with status 'RETURN_VALUE_TRUE' received (callback ID=0x25). DEBUG 2019-05-29 08:15:49,822 (Z-Wave): RX_Session_Layer : Waiting 64 983 [ms] for 'ZW_SendData' callback frame (callback ID=0x25). DEBUG 2019-05-29 08:15:49,885 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:49,885 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x05, 0x00, 0x13, 0x25, 0x00, 0xCC] DEBUG 2019-05-29 08:15:49,885 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x05, 0x00, 0x13, 0x25, 0x00, 0xCC] has been received. DEBUG 2019-05-29 08:15:49,885 (Z-Wave): RX_Session_Layer : Callback [0x01, 0x05, 0x00, 0x13, 0x25, 0x00, 0xCC] (callback ID=0x25) with state 'TRANSMIT_COMPLETE_OK' received -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x2B], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x25)' successfully executed. DEBUG 2019-05-29 08:15:49,885 (Z-Wave): RX_Session_Layer : Add function to pending transaction list (size='1') : ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x2B], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x25) DEBUG 2019-05-29 08:15:49,932 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:49,932 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x0A, 0x00, 0x04, 0x00, 0x33, 0x04, 0x86, 0x14, 0x2B, 0x01, 0x7E] DEBUG 2019-05-29 08:15:49,932 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x0A, 0x00, 0x04, 0x00, 0x33, 0x04, 0x86, 0x14, 0x2B, 0x01, 0x7E] has been received. DEBUG 2019-05-29 08:15:49,932 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_VERSION::VERSION_COMMAND_CLASS_REPORT (Retry='1'), CommandClass='COMMAND_CLASS_SCENE_ACTIVATION', Version='1']. DEBUG 2019-05-29 08:15:49,932 (Z-Wave): Node_Initializer : Node '51' : All command class versions of the root device have been updated. DEBUG 2019-05-29 08:15:49,932 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_VERSION::VERSION_GET (Retry='1')]... DEBUG 2019-05-29 08:15:49,932 (Z-Wave): RX_Session_Layer : Removed function from pending transaction list (size='0') : ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x2B], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x25) DEBUG 2019-05-29 08:15:49,932 (Z-Wave): Controller_API : Enqueue (WORKING-Queue, Count=1) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x86, 0x11], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:49,932 (Z-Wave): Controller_API : Dequeue (WORKING-Queue, Count=0) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x86, 0x11], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:49,932 (Z-Wave): TX_Session_Layer : Executing Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x86, 0x11], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'... DEBUG 2019-05-29 08:15:49,932 (Z-Wave): TX_Session_Layer : Send (repeat count=1) Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x86, 0x11], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x26)' request (callback ID=0x26). DEBUG 2019-05-29 08:15:49,932 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x09, 0x00, 0x13, 0x33, 0x02, 0x86, 0x11, 0x05, 0x26, 0x60]. DEBUG 2019-05-29 08:15:49,947 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06] DEBUG 2019-05-29 08:15:49,947 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x09, 0x00, 0x13, 0x33, 0x02, 0x86, 0x11, 0x05, 0x26, 0x60] transmission OK. DEBUG 2019-05-29 08:15:49,947 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x86, 0x11], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x26)' has been successfully sent - waiting 5 000 [ms] for response frame. DEBUG 2019-05-29 08:15:49,947 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:49,947 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x04, 0x01, 0x13, 0x01, 0xE8] DEBUG 2019-05-29 08:15:49,947 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] has been received. DEBUG 2019-05-29 08:15:49,947 (Z-Wave): RX_Session_Layer : 'ZW_SendData' response [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] with status 'RETURN_VALUE_TRUE' received (callback ID=0x26). DEBUG 2019-05-29 08:15:49,947 (Z-Wave): RX_Session_Layer : Waiting 64 984 [ms] for 'ZW_SendData' callback frame (callback ID=0x26). DEBUG 2019-05-29 08:15:50,010 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:50,010 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x05, 0x00, 0x13, 0x26, 0x00, 0xCF] DEBUG 2019-05-29 08:15:50,010 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x05, 0x00, 0x13, 0x26, 0x00, 0xCF] has been received. DEBUG 2019-05-29 08:15:50,025 (Z-Wave): RX_Session_Layer : Callback [0x01, 0x05, 0x00, 0x13, 0x26, 0x00, 0xCF] (callback ID=0x26) with state 'TRANSMIT_COMPLETE_OK' received -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x86, 0x11], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x26)' successfully executed. DEBUG 2019-05-29 08:15:50,025 (Z-Wave): RX_Session_Layer : Add function to pending transaction list (size='1') : ZW_SendData(NodeID=51, Payload=[0x86, 0x11], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x26) DEBUG 2019-05-29 08:15:50,057 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:50,057 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x0D, 0x00, 0x04, 0x00, 0x33, 0x07, 0x86, 0x12, 0x03, 0x03, 0x34, 0x02, 0x01, 0x61] DEBUG 2019-05-29 08:15:50,057 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x0D, 0x00, 0x04, 0x00, 0x33, 0x07, 0x86, 0x12, 0x03, 0x03, 0x34, 0x02, 0x01, 0x61] has been received. DEBUG 2019-05-29 08:15:50,072 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_VERSION::VERSION_REPORT (Retry='1'), ZWaveLibType='ZW_LIB_SLAVE_ENHANCED', SDKVersion='SDK_VERSION_UNKNOWN', AppVersion='2.1']. DEBUG 2019-05-29 08:15:50,072 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_MANUFACTURER_SPECIFIC::MANUFACTURER_SPECIFIC_GET (Retry='1')]... DEBUG 2019-05-29 08:15:50,072 (Z-Wave): RX_Session_Layer : Removed function from pending transaction list (size='0') : ZW_SendData(NodeID=51, Payload=[0x86, 0x11], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x26) DEBUG 2019-05-29 08:15:50,072 (Z-Wave): Controller_API : Enqueue (WORKING-Queue, Count=1) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x72, 0x04], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:50,072 (Z-Wave): Controller_API : Dequeue (WORKING-Queue, Count=0) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x72, 0x04], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:50,072 (Z-Wave): TX_Session_Layer : Executing Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x72, 0x04], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'... DEBUG 2019-05-29 08:15:50,072 (Z-Wave): TX_Session_Layer : Send (repeat count=1) Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x72, 0x04], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x27)' request (callback ID=0x27). DEBUG 2019-05-29 08:15:50,072 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x09, 0x00, 0x13, 0x33, 0x02, 0x72, 0x04, 0x05, 0x27, 0x80]. DEBUG 2019-05-29 08:15:50,088 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06] DEBUG 2019-05-29 08:15:50,088 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x09, 0x00, 0x13, 0x33, 0x02, 0x72, 0x04, 0x05, 0x27, 0x80] transmission OK. DEBUG 2019-05-29 08:15:50,088 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x72, 0x04], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x27)' has been successfully sent - waiting 5 000 [ms] for response frame. DEBUG 2019-05-29 08:15:50,088 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:50,088 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x04, 0x01, 0x13, 0x01, 0xE8] DEBUG 2019-05-29 08:15:50,088 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] has been received. DEBUG 2019-05-29 08:15:50,088 (Z-Wave): RX_Session_Layer : 'ZW_SendData' response [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] with status 'RETURN_VALUE_TRUE' received (callback ID=0x27). DEBUG 2019-05-29 08:15:50,088 (Z-Wave): RX_Session_Layer : Waiting 64 985 [ms] for 'ZW_SendData' callback frame (callback ID=0x27). DEBUG 2019-05-29 08:15:50,150 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:50,150 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x05, 0x00, 0x13, 0x27, 0x00, 0xCE] DEBUG 2019-05-29 08:15:50,150 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x05, 0x00, 0x13, 0x27, 0x00, 0xCE] has been received. DEBUG 2019-05-29 08:15:50,150 (Z-Wave): RX_Session_Layer : Callback [0x01, 0x05, 0x00, 0x13, 0x27, 0x00, 0xCE] (callback ID=0x27) with state 'TRANSMIT_COMPLETE_OK' received -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x72, 0x04], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x27)' successfully executed. DEBUG 2019-05-29 08:15:50,150 (Z-Wave): RX_Session_Layer : Add function to pending transaction list (size='1') : ZW_SendData(NodeID=51, Payload=[0x72, 0x04], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x27) DEBUG 2019-05-29 08:15:50,197 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:50,197 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x0E, 0x00, 0x04, 0x00, 0x33, 0x08, 0x72, 0x05, 0x01, 0x0F, 0x05, 0x01, 0x10, 0x02, 0xA1] DEBUG 2019-05-29 08:15:50,197 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x0E, 0x00, 0x04, 0x00, 0x33, 0x08, 0x72, 0x05, 0x01, 0x0F, 0x05, 0x01, 0x10, 0x02, 0xA1] has been received. DEBUG 2019-05-29 08:15:50,197 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_MANUFACTURER_SPECIFIC::MANUFACTURER_SPECIFIC_REPORT (Retry='1'), Manufacturer='Fibargroup', ProductTypeID='0x0501', ProductID='0x1002']. DEBUG 2019-05-29 08:15:50,197 (Z-Wave): Node_Initializer : Node '51' : Configure parameters... DEBUG 2019-05-29 08:15:50,197 (Z-Wave): RX_Session_Layer : Removed function from pending transaction list (size='0') : ZW_SendData(NodeID=51, Payload=[0x72, 0x04], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x27) DEBUG 2019-05-29 08:15:50,213 (Z-Wave): Node_Initializer : Node '51' : Requesting multi channel info... DEBUG 2019-05-29 08:15:50,213 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_MULTI_CHANNEL_V2::MULTI_CHANNEL_END_POINT_GET (Retry='1')]... DEBUG 2019-05-29 08:15:50,213 (Z-Wave): Controller_API : Enqueue (WORKING-Queue, Count=1) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x60, 0x07], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:50,213 (Z-Wave): Controller_API : Dequeue (WORKING-Queue, Count=0) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x60, 0x07], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:50,213 (Z-Wave): TX_Session_Layer : Executing Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x60, 0x07], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'... DEBUG 2019-05-29 08:15:50,213 (Z-Wave): TX_Session_Layer : Send (repeat count=1) Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x60, 0x07], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x28)' request (callback ID=0x28). DEBUG 2019-05-29 08:15:50,213 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x09, 0x00, 0x13, 0x33, 0x02, 0x60, 0x07, 0x05, 0x28, 0x9E]. DEBUG 2019-05-29 08:15:50,229 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06] DEBUG 2019-05-29 08:15:50,229 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x09, 0x00, 0x13, 0x33, 0x02, 0x60, 0x07, 0x05, 0x28, 0x9E] transmission OK. DEBUG 2019-05-29 08:15:50,229 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x60, 0x07], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x28)' has been successfully sent - waiting 5 000 [ms] for response frame. DEBUG 2019-05-29 08:15:50,229 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:50,229 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x04, 0x01, 0x13, 0x01, 0xE8] DEBUG 2019-05-29 08:15:50,229 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] has been received. DEBUG 2019-05-29 08:15:50,229 (Z-Wave): RX_Session_Layer : 'ZW_SendData' response [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] with status 'RETURN_VALUE_TRUE' received (callback ID=0x28). DEBUG 2019-05-29 08:15:50,229 (Z-Wave): RX_Session_Layer : Waiting 64 985 [ms] for 'ZW_SendData' callback frame (callback ID=0x28). DEBUG 2019-05-29 08:15:50,275 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:50,275 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x05, 0x00, 0x13, 0x28, 0x00, 0xC1] DEBUG 2019-05-29 08:15:50,291 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x05, 0x00, 0x13, 0x28, 0x00, 0xC1] has been received. DEBUG 2019-05-29 08:15:50,291 (Z-Wave): RX_Session_Layer : Callback [0x01, 0x05, 0x00, 0x13, 0x28, 0x00, 0xC1] (callback ID=0x28) with state 'TRANSMIT_COMPLETE_OK' received -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x60, 0x07], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x28)' successfully executed. DEBUG 2019-05-29 08:15:50,291 (Z-Wave): RX_Session_Layer : Add function to pending transaction list (size='1') : ZW_SendData(NodeID=51, Payload=[0x60, 0x07], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x28) DEBUG 2019-05-29 08:15:50,322 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:50,322 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x0A, 0x00, 0x04, 0x00, 0x33, 0x04, 0x60, 0x08, 0x00, 0x03, 0xAD] DEBUG 2019-05-29 08:15:50,322 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x0A, 0x00, 0x04, 0x00, 0x33, 0x04, 0x60, 0x08, 0x00, 0x03, 0xAD] has been received. DEBUG 2019-05-29 08:15:50,338 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_MULTI_CHANNEL_V2::MULTI_CHANNEL_END_POINT_REPORT (Retry='1'), EndPoints='3', Identical='NO', Dynamic='NO'] DEBUG 2019-05-29 08:15:50,338 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_MULTI_CHANNEL_V2::MULTI_CHANNEL_CAPABILITY_GET (Retry='1'), EndPoint='1'] DEBUG 2019-05-29 08:15:50,338 (Z-Wave): RX_Session_Layer : Removed function from pending transaction list (size='0') : ZW_SendData(NodeID=51, Payload=[0x60, 0x07], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x28) DEBUG 2019-05-29 08:15:50,338 (Z-Wave): Controller_API : Enqueue (WORKING-Queue, Count=1) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x60, 0x09, 0x01], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:50,338 (Z-Wave): Controller_API : Dequeue (WORKING-Queue, Count=0) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x60, 0x09, 0x01], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:50,338 (Z-Wave): TX_Session_Layer : Executing Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x60, 0x09, 0x01], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'... DEBUG 2019-05-29 08:15:50,338 (Z-Wave): TX_Session_Layer : Send (repeat count=1) Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x60, 0x09, 0x01], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x29)' request (callback ID=0x29). DEBUG 2019-05-29 08:15:50,338 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x0A, 0x00, 0x13, 0x33, 0x03, 0x60, 0x09, 0x01, 0x05, 0x29, 0x92]. DEBUG 2019-05-29 08:15:50,354 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06] DEBUG 2019-05-29 08:15:50,354 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x0A, 0x00, 0x13, 0x33, 0x03, 0x60, 0x09, 0x01, 0x05, 0x29, 0x92] transmission OK. DEBUG 2019-05-29 08:15:50,354 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:50,354 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x04, 0x01, 0x13, 0x01, 0xE8] DEBUG 2019-05-29 08:15:50,369 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x60, 0x09, 0x01], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x29)' has been successfully sent - waiting 5 000 [ms] for response frame. DEBUG 2019-05-29 08:15:50,369 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] has been received. DEBUG 2019-05-29 08:15:50,369 (Z-Wave): RX_Session_Layer : 'ZW_SendData' response [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] with status 'RETURN_VALUE_TRUE' received (callback ID=0x29). DEBUG 2019-05-29 08:15:50,385 (Z-Wave): RX_Session_Layer : Waiting 64 969 [ms] for 'ZW_SendData' callback frame (callback ID=0x29). DEBUG 2019-05-29 08:15:50,416 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:50,416 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x05, 0x00, 0x13, 0x29, 0x00, 0xC0] DEBUG 2019-05-29 08:15:50,432 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x05, 0x00, 0x13, 0x29, 0x00, 0xC0] has been received. DEBUG 2019-05-29 08:15:50,432 (Z-Wave): RX_Session_Layer : Callback [0x01, 0x05, 0x00, 0x13, 0x29, 0x00, 0xC0] (callback ID=0x29) with state 'TRANSMIT_COMPLETE_OK' received -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x60, 0x09, 0x01], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x29)' successfully executed. DEBUG 2019-05-29 08:15:50,447 (Z-Wave): RX_Session_Layer : Add function to pending transaction list (size='1') : ZW_SendData(NodeID=51, Payload=[0x60, 0x09, 0x01], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x29) DEBUG 2019-05-29 08:15:50,463 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:50,463 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x0D, 0x00, 0x04, 0x00, 0x33, 0x07, 0x60, 0x0A, 0x01, 0x20, 0x01, 0x30, 0x9C, 0x24] DEBUG 2019-05-29 08:15:50,525 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x0D, 0x00, 0x04, 0x00, 0x33, 0x07, 0x60, 0x0A, 0x01, 0x20, 0x01, 0x30, 0x9C, 0x24] has been received. DEBUG 2019-05-29 08:15:50,541 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_MULTI_CHANNEL_V2::MULTI_CHANNEL_CAPABILITY_REPORT (Retry='1'), EndPoint='1', Generic='GENERIC_TYPE_SENSOR_BINARY', Specific='SPECIFIC_TYPE_ROUTING_SENSOR_BINARY', SupportedClasses : [COMMAND_CLASS_SENSOR_BINARY, COMMAND_CLASS_SENSOR_ALARM], ControlledClasses : [], Dynamic='false'] DEBUG 2019-05-29 08:15:50,541 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_MULTI_CHANNEL_V2::MULTI_CHANNEL_CAPABILITY_GET (Retry='1'), EndPoint='2'] DEBUG 2019-05-29 08:15:50,541 (Z-Wave): Controller_API : Enqueue (WORKING-Queue, Count=1) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x60, 0x09, 0x02], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:50,541 (Z-Wave): RX_Session_Layer : Removed function from pending transaction list (size='0') : ZW_SendData(NodeID=51, Payload=[0x60, 0x09, 0x01], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x29) DEBUG 2019-05-29 08:15:50,541 (Z-Wave): Controller_API : Dequeue (WORKING-Queue, Count=0) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x60, 0x09, 0x02], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:50,541 (Z-Wave): TX_Session_Layer : Executing Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x60, 0x09, 0x02], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'... DEBUG 2019-05-29 08:15:50,557 (Z-Wave): TX_Session_Layer : Send (repeat count=1) Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x60, 0x09, 0x02], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x2A)' request (callback ID=0x2A). DEBUG 2019-05-29 08:15:50,557 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x0A, 0x00, 0x13, 0x33, 0x03, 0x60, 0x09, 0x02, 0x05, 0x2A, 0x92]. DEBUG 2019-05-29 08:15:50,557 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06] DEBUG 2019-05-29 08:15:50,557 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x0A, 0x00, 0x13, 0x33, 0x03, 0x60, 0x09, 0x02, 0x05, 0x2A, 0x92] transmission OK. DEBUG 2019-05-29 08:15:50,557 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x60, 0x09, 0x02], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x2A)' has been successfully sent - waiting 5 000 [ms] for response frame. DEBUG 2019-05-29 08:15:50,572 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:50,572 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x04, 0x01, 0x13, 0x01, 0xE8] DEBUG 2019-05-29 08:15:50,572 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] has been received. DEBUG 2019-05-29 08:15:50,572 (Z-Wave): RX_Session_Layer : 'ZW_SendData' response [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] with status 'RETURN_VALUE_TRUE' received (callback ID=0x2A). DEBUG 2019-05-29 08:15:50,572 (Z-Wave): RX_Session_Layer : Waiting 64 973 [ms] for 'ZW_SendData' callback frame (callback ID=0x2A). DEBUG 2019-05-29 08:15:50,604 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:50,604 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x05, 0x00, 0x13, 0x2A, 0x00, 0xC3] DEBUG 2019-05-29 08:15:50,604 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x05, 0x00, 0x13, 0x2A, 0x00, 0xC3] has been received. DEBUG 2019-05-29 08:15:50,604 (Z-Wave): RX_Session_Layer : Callback [0x01, 0x05, 0x00, 0x13, 0x2A, 0x00, 0xC3] (callback ID=0x2A) with state 'TRANSMIT_COMPLETE_OK' received -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x60, 0x09, 0x02], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x2A)' successfully executed. DEBUG 2019-05-29 08:15:50,650 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:50,650 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x0D, 0x00, 0x04, 0x00, 0x33, 0x07, 0x60, 0x0A, 0x02, 0x20, 0x01, 0x30, 0x9C, 0x27] DEBUG 2019-05-29 08:15:50,650 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x0D, 0x00, 0x04, 0x00, 0x33, 0x07, 0x60, 0x0A, 0x02, 0x20, 0x01, 0x30, 0x9C, 0x27] has been received. DEBUG 2019-05-29 08:15:50,650 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_MULTI_CHANNEL_V2::MULTI_CHANNEL_CAPABILITY_REPORT (Retry='1'), EndPoint='2', Generic='GENERIC_TYPE_SENSOR_BINARY', Specific='SPECIFIC_TYPE_ROUTING_SENSOR_BINARY', SupportedClasses : [COMMAND_CLASS_SENSOR_BINARY, COMMAND_CLASS_SENSOR_ALARM], ControlledClasses : [], Dynamic='false'] DEBUG 2019-05-29 08:15:50,650 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_MULTI_CHANNEL_V2::MULTI_CHANNEL_CAPABILITY_GET (Retry='1'), EndPoint='3'] DEBUG 2019-05-29 08:15:50,650 (Z-Wave): Controller_API : Enqueue (WORKING-Queue, Count=1) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x60, 0x09, 0x03], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:50,682 (Z-Wave): Controller_API : Dequeue (WORKING-Queue, Count=0) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x60, 0x09, 0x03], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:50,682 (Z-Wave): TX_Session_Layer : Executing Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x60, 0x09, 0x03], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'... DEBUG 2019-05-29 08:15:50,682 (Z-Wave): TX_Session_Layer : Send (repeat count=1) Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x60, 0x09, 0x03], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x2B)' request (callback ID=0x2B). DEBUG 2019-05-29 08:15:50,682 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x0A, 0x00, 0x13, 0x33, 0x03, 0x60, 0x09, 0x03, 0x05, 0x2B, 0x92]. DEBUG 2019-05-29 08:15:50,682 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06] DEBUG 2019-05-29 08:15:50,682 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x0A, 0x00, 0x13, 0x33, 0x03, 0x60, 0x09, 0x03, 0x05, 0x2B, 0x92] transmission OK. DEBUG 2019-05-29 08:15:50,682 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x60, 0x09, 0x03], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x2B)' has been successfully sent - waiting 5 000 [ms] for response frame. DEBUG 2019-05-29 08:15:50,697 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:50,697 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x04, 0x01, 0x13, 0x01, 0xE8] DEBUG 2019-05-29 08:15:50,697 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] has been received. DEBUG 2019-05-29 08:15:50,697 (Z-Wave): RX_Session_Layer : 'ZW_SendData' response [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] with status 'RETURN_VALUE_TRUE' received (callback ID=0x2B). DEBUG 2019-05-29 08:15:50,697 (Z-Wave): RX_Session_Layer : Waiting 64 983 [ms] for 'ZW_SendData' callback frame (callback ID=0x2B). DEBUG 2019-05-29 08:15:50,744 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:50,744 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x05, 0x00, 0x13, 0x2B, 0x00, 0xC2] DEBUG 2019-05-29 08:15:50,744 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x05, 0x00, 0x13, 0x2B, 0x00, 0xC2] has been received. DEBUG 2019-05-29 08:15:50,744 (Z-Wave): RX_Session_Layer : Callback [0x01, 0x05, 0x00, 0x13, 0x2B, 0x00, 0xC2] (callback ID=0x2B) with state 'TRANSMIT_COMPLETE_OK' received -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x60, 0x09, 0x03], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x2B)' successfully executed. DEBUG 2019-05-29 08:15:50,744 (Z-Wave): RX_Session_Layer : Add function to pending transaction list (size='1') : ZW_SendData(NodeID=51, Payload=[0x60, 0x09, 0x03], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x2B) DEBUG 2019-05-29 08:15:50,791 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:50,791 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x0C, 0x00, 0x04, 0x00, 0x33, 0x06, 0x60, 0x0A, 0x03, 0x21, 0x01, 0x31, 0xBA] DEBUG 2019-05-29 08:15:50,791 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x0C, 0x00, 0x04, 0x00, 0x33, 0x06, 0x60, 0x0A, 0x03, 0x21, 0x01, 0x31, 0xBA] has been received. DEBUG 2019-05-29 08:15:50,791 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_MULTI_CHANNEL_V2::MULTI_CHANNEL_CAPABILITY_REPORT (Retry='1'), EndPoint='3', Generic='GENERIC_TYPE_SENSOR_MULTILEVEL', Specific='SPECIFIC_TYPE_ROUTING_SENSOR_MULTILEVEL', SupportedClasses : [COMMAND_CLASS_SENSOR_MULTILEVEL], ControlledClasses : [], Dynamic='false'] DEBUG 2019-05-29 08:15:50,791 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_VERSION::VERSION_COMMAND_CLASS_GET (Retry='1'), CommandClass='COMMAND_CLASS_SENSOR_BINARY']... DEBUG 2019-05-29 08:15:50,791 (Z-Wave): RX_Session_Layer : Removed function from pending transaction list (size='0') : ZW_SendData(NodeID=51, Payload=[0x60, 0x09, 0x03], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x2B) DEBUG 2019-05-29 08:15:50,791 (Z-Wave): Controller_API : Enqueue (WORKING-Queue, Count=1) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x30], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:50,791 (Z-Wave): Controller_API : Dequeue (WORKING-Queue, Count=0) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x30], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:50,791 (Z-Wave): TX_Session_Layer : Executing Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x30], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'... DEBUG 2019-05-29 08:15:50,791 (Z-Wave): TX_Session_Layer : Send (repeat count=1) Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x30], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x2C)' request (callback ID=0x2C). DEBUG 2019-05-29 08:15:50,791 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x0A, 0x00, 0x13, 0x33, 0x03, 0x86, 0x13, 0x30, 0x05, 0x2C, 0x5A]. DEBUG 2019-05-29 08:15:50,807 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06] DEBUG 2019-05-29 08:15:50,807 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x0A, 0x00, 0x13, 0x33, 0x03, 0x86, 0x13, 0x30, 0x05, 0x2C, 0x5A] transmission OK. DEBUG 2019-05-29 08:15:50,807 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x30], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x2C)' has been successfully sent - waiting 5 000 [ms] for response frame. DEBUG 2019-05-29 08:15:50,807 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:50,807 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x04, 0x01, 0x13, 0x01, 0xE8] DEBUG 2019-05-29 08:15:50,807 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] has been received. DEBUG 2019-05-29 08:15:50,807 (Z-Wave): RX_Session_Layer : 'ZW_SendData' response [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] with status 'RETURN_VALUE_TRUE' received (callback ID=0x2C). DEBUG 2019-05-29 08:15:50,807 (Z-Wave): RX_Session_Layer : Waiting 64 983 [ms] for 'ZW_SendData' callback frame (callback ID=0x2C). DEBUG 2019-05-29 08:15:50,869 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:50,869 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x05, 0x00, 0x13, 0x2C, 0x00, 0xC5] DEBUG 2019-05-29 08:15:50,869 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x05, 0x00, 0x13, 0x2C, 0x00, 0xC5] has been received. DEBUG 2019-05-29 08:15:50,869 (Z-Wave): RX_Session_Layer : Callback [0x01, 0x05, 0x00, 0x13, 0x2C, 0x00, 0xC5] (callback ID=0x2C) with state 'TRANSMIT_COMPLETE_OK' received -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x30], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x2C)' successfully executed. DEBUG 2019-05-29 08:15:50,869 (Z-Wave): RX_Session_Layer : Add function to pending transaction list (size='1') : ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x30], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x2C) DEBUG 2019-05-29 08:15:50,916 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:50,916 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x0A, 0x00, 0x04, 0x00, 0x33, 0x04, 0x86, 0x14, 0x30, 0x01, 0x65] DEBUG 2019-05-29 08:15:50,916 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x0A, 0x00, 0x04, 0x00, 0x33, 0x04, 0x86, 0x14, 0x30, 0x01, 0x65] has been received. DEBUG 2019-05-29 08:15:50,916 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_VERSION::VERSION_COMMAND_CLASS_REPORT (Retry='1'), CommandClass='COMMAND_CLASS_SENSOR_BINARY', Version='1']. DEBUG 2019-05-29 08:15:50,916 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_VERSION::VERSION_COMMAND_CLASS_GET (Retry='1'), CommandClass='COMMAND_CLASS_SENSOR_ALARM']... DEBUG 2019-05-29 08:15:50,916 (Z-Wave): Controller_API : Enqueue (WORKING-Queue, Count=1) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x9C], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:50,916 (Z-Wave): Controller_API : Dequeue (WORKING-Queue, Count=0) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x9C], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:50,916 (Z-Wave): TX_Session_Layer : Executing Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x9C], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'... DEBUG 2019-05-29 08:15:50,916 (Z-Wave): TX_Session_Layer : Send (repeat count=1) Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x9C], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x2D)' request (callback ID=0x2D). DEBUG 2019-05-29 08:15:50,916 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x0A, 0x00, 0x13, 0x33, 0x03, 0x86, 0x13, 0x9C, 0x05, 0x2D, 0xF7]. DEBUG 2019-05-29 08:15:50,916 (Z-Wave): RX_Session_Layer : Removed function from pending transaction list (size='0') : ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x30], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x2C) DEBUG 2019-05-29 08:15:50,932 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06] DEBUG 2019-05-29 08:15:50,932 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x0A, 0x00, 0x13, 0x33, 0x03, 0x86, 0x13, 0x9C, 0x05, 0x2D, 0xF7] transmission OK. DEBUG 2019-05-29 08:15:50,932 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x9C], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x2D)' has been successfully sent - waiting 5 000 [ms] for response frame. DEBUG 2019-05-29 08:15:50,932 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:50,932 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x04, 0x01, 0x13, 0x01, 0xE8] DEBUG 2019-05-29 08:15:50,932 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] has been received. DEBUG 2019-05-29 08:15:50,932 (Z-Wave): RX_Session_Layer : 'ZW_SendData' response [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] with status 'RETURN_VALUE_TRUE' received (callback ID=0x2D). DEBUG 2019-05-29 08:15:50,932 (Z-Wave): RX_Session_Layer : Waiting 64 982 [ms] for 'ZW_SendData' callback frame (callback ID=0x2D). DEBUG 2019-05-29 08:15:51,010 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:51,010 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x05, 0x00, 0x13, 0x2D, 0x00, 0xC4] DEBUG 2019-05-29 08:15:51,010 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x05, 0x00, 0x13, 0x2D, 0x00, 0xC4] has been received. DEBUG 2019-05-29 08:15:51,010 (Z-Wave): RX_Session_Layer : Callback [0x01, 0x05, 0x00, 0x13, 0x2D, 0x00, 0xC4] (callback ID=0x2D) with state 'TRANSMIT_COMPLETE_OK' received -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x9C], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x2D)' successfully executed. DEBUG 2019-05-29 08:15:51,010 (Z-Wave): RX_Session_Layer : Add function to pending transaction list (size='1') : ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x9C], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x2D) DEBUG 2019-05-29 08:15:51,057 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:51,057 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x0A, 0x00, 0x04, 0x00, 0x33, 0x04, 0x86, 0x14, 0x9C, 0x01, 0xC9] DEBUG 2019-05-29 08:15:51,057 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x0A, 0x00, 0x04, 0x00, 0x33, 0x04, 0x86, 0x14, 0x9C, 0x01, 0xC9] has been received. DEBUG 2019-05-29 08:15:51,057 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_VERSION::VERSION_COMMAND_CLASS_REPORT (Retry='1'), CommandClass='COMMAND_CLASS_SENSOR_ALARM', Version='1']. DEBUG 2019-05-29 08:15:51,057 (Z-Wave): Node_Initializer : Node '51:1' : All command class versions of endpoint '1' have been updated. DEBUG 2019-05-29 08:15:51,057 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_VERSION::VERSION_COMMAND_CLASS_GET (Retry='1'), CommandClass='COMMAND_CLASS_SENSOR_BINARY']... DEBUG 2019-05-29 08:15:51,057 (Z-Wave): Controller_API : Enqueue (WORKING-Queue, Count=1) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x30], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:51,057 (Z-Wave): RX_Session_Layer : Removed function from pending transaction list (size='0') : ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x9C], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x2D) DEBUG 2019-05-29 08:15:51,057 (Z-Wave): Controller_API : Dequeue (WORKING-Queue, Count=0) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x30], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:51,057 (Z-Wave): TX_Session_Layer : Executing Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x30], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'... DEBUG 2019-05-29 08:15:51,057 (Z-Wave): TX_Session_Layer : Send (repeat count=1) Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x30], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x2E)' request (callback ID=0x2E). DEBUG 2019-05-29 08:15:51,057 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x0A, 0x00, 0x13, 0x33, 0x03, 0x86, 0x13, 0x30, 0x05, 0x2E, 0x58]. DEBUG 2019-05-29 08:15:51,072 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06] DEBUG 2019-05-29 08:15:51,072 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x0A, 0x00, 0x13, 0x33, 0x03, 0x86, 0x13, 0x30, 0x05, 0x2E, 0x58] transmission OK. DEBUG 2019-05-29 08:15:51,072 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x30], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x2E)' has been successfully sent - waiting 5 000 [ms] for response frame. DEBUG 2019-05-29 08:15:51,072 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:51,072 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x04, 0x01, 0x13, 0x01, 0xE8] DEBUG 2019-05-29 08:15:51,072 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] has been received. DEBUG 2019-05-29 08:15:51,072 (Z-Wave): RX_Session_Layer : 'ZW_SendData' response [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] with status 'RETURN_VALUE_TRUE' received (callback ID=0x2E). DEBUG 2019-05-29 08:15:51,072 (Z-Wave): RX_Session_Layer : Waiting 64 984 [ms] for 'ZW_SendData' callback frame (callback ID=0x2E). DEBUG 2019-05-29 08:15:51,135 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:51,135 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x05, 0x00, 0x13, 0x2E, 0x00, 0xC7] DEBUG 2019-05-29 08:15:51,135 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x05, 0x00, 0x13, 0x2E, 0x00, 0xC7] has been received. DEBUG 2019-05-29 08:15:51,135 (Z-Wave): RX_Session_Layer : Callback [0x01, 0x05, 0x00, 0x13, 0x2E, 0x00, 0xC7] (callback ID=0x2E) with state 'TRANSMIT_COMPLETE_OK' received -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x30], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x2E)' successfully executed. DEBUG 2019-05-29 08:15:51,150 (Z-Wave): RX_Session_Layer : Add function to pending transaction list (size='1') : ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x30], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x2E) DEBUG 2019-05-29 08:15:51,182 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:51,182 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x0A, 0x00, 0x04, 0x00, 0x33, 0x04, 0x86, 0x14, 0x30, 0x01, 0x65] DEBUG 2019-05-29 08:15:51,182 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x0A, 0x00, 0x04, 0x00, 0x33, 0x04, 0x86, 0x14, 0x30, 0x01, 0x65] has been received. DEBUG 2019-05-29 08:15:51,182 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_VERSION::VERSION_COMMAND_CLASS_REPORT (Retry='1'), CommandClass='COMMAND_CLASS_SENSOR_BINARY', Version='1']. DEBUG 2019-05-29 08:15:51,182 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_VERSION::VERSION_COMMAND_CLASS_GET (Retry='1'), CommandClass='COMMAND_CLASS_SENSOR_ALARM']... DEBUG 2019-05-29 08:15:51,182 (Z-Wave): RX_Session_Layer : Removed function from pending transaction list (size='0') : ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x30], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x2E) DEBUG 2019-05-29 08:15:51,182 (Z-Wave): Controller_API : Enqueue (WORKING-Queue, Count=1) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x9C], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:51,182 (Z-Wave): Controller_API : Dequeue (WORKING-Queue, Count=0) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x9C], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:51,182 (Z-Wave): TX_Session_Layer : Executing Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x9C], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'... DEBUG 2019-05-29 08:15:51,182 (Z-Wave): TX_Session_Layer : Send (repeat count=1) Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x9C], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x2F)' request (callback ID=0x2F). DEBUG 2019-05-29 08:15:51,182 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x0A, 0x00, 0x13, 0x33, 0x03, 0x86, 0x13, 0x9C, 0x05, 0x2F, 0xF5]. DEBUG 2019-05-29 08:15:51,197 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06] DEBUG 2019-05-29 08:15:51,197 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x0A, 0x00, 0x13, 0x33, 0x03, 0x86, 0x13, 0x9C, 0x05, 0x2F, 0xF5] transmission OK. DEBUG 2019-05-29 08:15:51,197 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x9C], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x2F)' has been successfully sent - waiting 5 000 [ms] for response frame. DEBUG 2019-05-29 08:15:51,197 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:51,197 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x04, 0x01, 0x13, 0x01, 0xE8] DEBUG 2019-05-29 08:15:51,197 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] has been received. DEBUG 2019-05-29 08:15:51,197 (Z-Wave): RX_Session_Layer : 'ZW_SendData' response [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] with status 'RETURN_VALUE_TRUE' received (callback ID=0x2F). DEBUG 2019-05-29 08:15:51,197 (Z-Wave): RX_Session_Layer : Waiting 64 984 [ms] for 'ZW_SendData' callback frame (callback ID=0x2F). DEBUG 2019-05-29 08:15:51,275 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:51,275 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x05, 0x00, 0x13, 0x2F, 0x00, 0xC6] DEBUG 2019-05-29 08:15:51,275 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x05, 0x00, 0x13, 0x2F, 0x00, 0xC6] has been received. DEBUG 2019-05-29 08:15:51,275 (Z-Wave): RX_Session_Layer : Callback [0x01, 0x05, 0x00, 0x13, 0x2F, 0x00, 0xC6] (callback ID=0x2F) with state 'TRANSMIT_COMPLETE_OK' received -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x9C], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x2F)' successfully executed. DEBUG 2019-05-29 08:15:51,275 (Z-Wave): RX_Session_Layer : Add function to pending transaction list (size='1') : ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x9C], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x2F) DEBUG 2019-05-29 08:15:51,322 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:51,322 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x0A, 0x00, 0x04, 0x00, 0x33, 0x04, 0x86, 0x14, 0x9C, 0x01, 0xC9] DEBUG 2019-05-29 08:15:51,322 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x0A, 0x00, 0x04, 0x00, 0x33, 0x04, 0x86, 0x14, 0x9C, 0x01, 0xC9] has been received. DEBUG 2019-05-29 08:15:51,322 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_VERSION::VERSION_COMMAND_CLASS_REPORT (Retry='1'), CommandClass='COMMAND_CLASS_SENSOR_ALARM', Version='1']. DEBUG 2019-05-29 08:15:51,322 (Z-Wave): Node_Initializer : Node '51:2' : All command class versions of endpoint '2' have been updated. DEBUG 2019-05-29 08:15:51,322 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_VERSION::VERSION_COMMAND_CLASS_GET (Retry='1'), CommandClass='COMMAND_CLASS_SENSOR_MULTILEVEL']... DEBUG 2019-05-29 08:15:51,322 (Z-Wave): Controller_API : Enqueue (WORKING-Queue, Count=1) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x31], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:51,322 (Z-Wave): Controller_API : Dequeue (WORKING-Queue, Count=0) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x31], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:51,322 (Z-Wave): TX_Session_Layer : Executing Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x31], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'... DEBUG 2019-05-29 08:15:51,322 (Z-Wave): TX_Session_Layer : Send (repeat count=1) Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x31], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x30)' request (callback ID=0x30). DEBUG 2019-05-29 08:15:51,322 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x0A, 0x00, 0x13, 0x33, 0x03, 0x86, 0x13, 0x31, 0x05, 0x30, 0x47]. DEBUG 2019-05-29 08:15:51,322 (Z-Wave): RX_Session_Layer : Removed function from pending transaction list (size='0') : ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x9C], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x2F) DEBUG 2019-05-29 08:15:51,338 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06] DEBUG 2019-05-29 08:15:51,338 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x0A, 0x00, 0x13, 0x33, 0x03, 0x86, 0x13, 0x31, 0x05, 0x30, 0x47] transmission OK. DEBUG 2019-05-29 08:15:51,338 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x31], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x30)' has been successfully sent - waiting 5 000 [ms] for response frame. DEBUG 2019-05-29 08:15:51,338 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:51,338 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x04, 0x01, 0x13, 0x01, 0xE8] DEBUG 2019-05-29 08:15:51,338 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] has been received. DEBUG 2019-05-29 08:15:51,338 (Z-Wave): RX_Session_Layer : 'ZW_SendData' response [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] with status 'RETURN_VALUE_TRUE' received (callback ID=0x30). DEBUG 2019-05-29 08:15:51,338 (Z-Wave): RX_Session_Layer : Waiting 64 983 [ms] for 'ZW_SendData' callback frame (callback ID=0x30). DEBUG 2019-05-29 08:15:51,400 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:51,400 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x05, 0x00, 0x13, 0x30, 0x00, 0xD9] DEBUG 2019-05-29 08:15:51,400 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x05, 0x00, 0x13, 0x30, 0x00, 0xD9] has been received. DEBUG 2019-05-29 08:15:51,400 (Z-Wave): RX_Session_Layer : Callback [0x01, 0x05, 0x00, 0x13, 0x30, 0x00, 0xD9] (callback ID=0x30) with state 'TRANSMIT_COMPLETE_OK' received -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x31], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x30)' successfully executed. DEBUG 2019-05-29 08:15:51,400 (Z-Wave): RX_Session_Layer : Add function to pending transaction list (size='1') : ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x31], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x30) DEBUG 2019-05-29 08:15:51,447 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:51,447 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x0A, 0x00, 0x04, 0x00, 0x33, 0x04, 0x86, 0x14, 0x31, 0x01, 0x64] DEBUG 2019-05-29 08:15:51,447 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x0A, 0x00, 0x04, 0x00, 0x33, 0x04, 0x86, 0x14, 0x31, 0x01, 0x64] has been received. DEBUG 2019-05-29 08:15:51,447 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_VERSION::VERSION_COMMAND_CLASS_REPORT (Retry='1'), CommandClass='COMMAND_CLASS_SENSOR_MULTILEVEL', Version='1']. DEBUG 2019-05-29 08:15:51,447 (Z-Wave): Node_Initializer : Node '51:3' : All command class versions of endpoint '3' have been updated. DEBUG 2019-05-29 08:15:51,447 (Z-Wave): Node_Initializer : Node '51' : ====== Init static data of command classes... DEBUG 2019-05-29 08:15:51,447 (Z-Wave): RX_Session_Layer : Removed function from pending transaction list (size='0') : ZW_SendData(NodeID=51, Payload=[0x86, 0x13, 0x31], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x30) DEBUG 2019-05-29 08:15:51,494 (Z-Wave): Node_Initializer : Node '51' : ------ Update static data of : [COMMAND_CLASS_SENSOR_BINARY] DEBUG 2019-05-29 08:15:51,494 (Z-Wave): Node_Initializer : Node '51' : ------ Update static data of : [COMMAND_CLASS_MULTI_CHANNEL_V2] DEBUG 2019-05-29 08:15:51,494 (Z-Wave): Node_Initializer : Node '51' : ------ Update static data of : [COMMAND_CLASS_ASSOCIATION_V2] DEBUG 2019-05-29 08:15:51,494 (Z-Wave): Node_Initializer : Node '51:0' : COMMAND_CLASS_ASSOCIATION - Read association group information (Retry='1'). DEBUG 2019-05-29 08:15:51,510 (Z-Wave): Association_Reader : Node '51' : [COMMAND_CLASS_ASSOCIATION_V2:ASSOCIATION_GROUPINGS_GET (Retry='1')]... DEBUG 2019-05-29 08:15:51,510 (Z-Wave): Controller_API : Enqueue (WORKING-Queue, Count=1) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x85, 0x05], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:51,525 (Z-Wave): Controller_API : Dequeue (WORKING-Queue, Count=0) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x85, 0x05], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:51,525 (Z-Wave): TX_Session_Layer : Executing Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x85, 0x05], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'... DEBUG 2019-05-29 08:15:51,525 (Z-Wave): TX_Session_Layer : Send (repeat count=1) Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x85, 0x05], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x31)' request (callback ID=0x31). DEBUG 2019-05-29 08:15:51,525 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x09, 0x00, 0x13, 0x33, 0x02, 0x85, 0x05, 0x05, 0x31, 0x60]. DEBUG 2019-05-29 08:15:51,541 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06] DEBUG 2019-05-29 08:15:51,541 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x09, 0x00, 0x13, 0x33, 0x02, 0x85, 0x05, 0x05, 0x31, 0x60] transmission OK. DEBUG 2019-05-29 08:15:51,541 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x85, 0x05], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x31)' has been successfully sent - waiting 5 000 [ms] for response frame. DEBUG 2019-05-29 08:15:51,541 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:51,557 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x04, 0x01, 0x13, 0x01, 0xE8] DEBUG 2019-05-29 08:15:51,557 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] has been received. DEBUG 2019-05-29 08:15:51,557 (Z-Wave): RX_Session_Layer : 'ZW_SendData' response [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] with status 'RETURN_VALUE_TRUE' received (callback ID=0x31). DEBUG 2019-05-29 08:15:51,557 (Z-Wave): RX_Session_Layer : Waiting 64 969 [ms] for 'ZW_SendData' callback frame (callback ID=0x31). DEBUG 2019-05-29 08:15:51,588 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:51,588 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x05, 0x00, 0x13, 0x31, 0x00, 0xD8] DEBUG 2019-05-29 08:15:51,588 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x05, 0x00, 0x13, 0x31, 0x00, 0xD8] has been received. DEBUG 2019-05-29 08:15:51,588 (Z-Wave): RX_Session_Layer : Callback [0x01, 0x05, 0x00, 0x13, 0x31, 0x00, 0xD8] (callback ID=0x31) with state 'TRANSMIT_COMPLETE_OK' received -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x85, 0x05], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x31)' successfully executed. DEBUG 2019-05-29 08:15:51,588 (Z-Wave): RX_Session_Layer : Add function to pending transaction list (size='1') : ZW_SendData(NodeID=51, Payload=[0x85, 0x05], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x31) DEBUG 2019-05-29 08:15:51,635 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:51,635 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x09, 0x00, 0x04, 0x00, 0x33, 0x03, 0x85, 0x06, 0x03, 0x42] DEBUG 2019-05-29 08:15:51,635 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x09, 0x00, 0x04, 0x00, 0x33, 0x03, 0x85, 0x06, 0x03, 0x42] has been received. DEBUG 2019-05-29 08:15:51,635 (Z-Wave): Association_Reader : Node '51' : [COMMAND_CLASS_ASSOCIATION_V2:ASSOCIATION_GROUPINGS_GET (Retry='1'), NumberOfGroups='3'] succeeded. DEBUG 2019-05-29 08:15:51,635 (Z-Wave): RX_Session_Layer : Removed function from pending transaction list (size='0') : ZW_SendData(NodeID=51, Payload=[0x85, 0x05], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x31) DEBUG 2019-05-29 08:15:51,635 (Z-Wave): Association_Reader : Node '51' : [COMMAND_CLASS_ASSOCIATION_V2:ASSOCIATION_GET (Retry='1'), GroupID='1' ]... DEBUG 2019-05-29 08:15:51,650 (Z-Wave): Controller_API : Enqueue (WORKING-Queue, Count=1) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x85, 0x02, 0x01], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:51,650 (Z-Wave): Controller_API : Dequeue (WORKING-Queue, Count=0) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x85, 0x02, 0x01], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:51,650 (Z-Wave): TX_Session_Layer : Executing Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x85, 0x02, 0x01], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'... DEBUG 2019-05-29 08:15:51,650 (Z-Wave): TX_Session_Layer : Send (repeat count=1) Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x85, 0x02, 0x01], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x32)' request (callback ID=0x32). DEBUG 2019-05-29 08:15:51,650 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x0A, 0x00, 0x13, 0x33, 0x03, 0x85, 0x02, 0x01, 0x05, 0x32, 0x67]. DEBUG 2019-05-29 08:15:51,666 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06] DEBUG 2019-05-29 08:15:51,666 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x0A, 0x00, 0x13, 0x33, 0x03, 0x85, 0x02, 0x01, 0x05, 0x32, 0x67] transmission OK. DEBUG 2019-05-29 08:15:51,666 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x85, 0x02, 0x01], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x32)' has been successfully sent - waiting 5 000 [ms] for response frame. DEBUG 2019-05-29 08:15:51,666 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:51,666 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x04, 0x01, 0x13, 0x01, 0xE8] DEBUG 2019-05-29 08:15:51,666 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] has been received. DEBUG 2019-05-29 08:15:51,666 (Z-Wave): RX_Session_Layer : 'ZW_SendData' response [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] with status 'RETURN_VALUE_TRUE' received (callback ID=0x32). DEBUG 2019-05-29 08:15:51,666 (Z-Wave): RX_Session_Layer : Waiting 64 983 [ms] for 'ZW_SendData' callback frame (callback ID=0x32). DEBUG 2019-05-29 08:15:51,728 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:51,728 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x05, 0x00, 0x13, 0x32, 0x00, 0xDB] DEBUG 2019-05-29 08:15:51,728 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x05, 0x00, 0x13, 0x32, 0x00, 0xDB] has been received. DEBUG 2019-05-29 08:15:51,728 (Z-Wave): RX_Session_Layer : Callback [0x01, 0x05, 0x00, 0x13, 0x32, 0x00, 0xDB] (callback ID=0x32) with state 'TRANSMIT_COMPLETE_OK' received -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x85, 0x02, 0x01], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x32)' successfully executed. DEBUG 2019-05-29 08:15:51,728 (Z-Wave): RX_Session_Layer : Add function to pending transaction list (size='1') : ZW_SendData(NodeID=51, Payload=[0x85, 0x02, 0x01], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x32) DEBUG 2019-05-29 08:15:51,775 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:51,775 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x0B, 0x00, 0x04, 0x00, 0x33, 0x05, 0x85, 0x03, 0x01, 0x05, 0x00, 0x44] DEBUG 2019-05-29 08:15:51,775 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x0B, 0x00, 0x04, 0x00, 0x33, 0x05, 0x85, 0x03, 0x01, 0x05, 0x00, 0x44] has been received. DEBUG 2019-05-29 08:15:51,775 (Z-Wave): Association_Reader : Node '51' : [COMMAND_CLASS_ASSOCIATION_V2:ASSOCIATION_GET (Retry='1'), GroupID='1', [Association Group : ID='1', Capacitiy='5' []]] succeeded. DEBUG 2019-05-29 08:15:51,775 (Z-Wave): Association_Reader : Node '51' : [COMMAND_CLASS_ASSOCIATION_V2:ASSOCIATION_GET (Retry='1'), GroupID='2' ]... DEBUG 2019-05-29 08:15:51,775 (Z-Wave): Controller_API : Enqueue (WORKING-Queue, Count=1) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x85, 0x02, 0x02], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:51,775 (Z-Wave): Controller_API : Dequeue (WORKING-Queue, Count=0) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x85, 0x02, 0x02], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:51,775 (Z-Wave): TX_Session_Layer : Executing Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x85, 0x02, 0x02], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'... DEBUG 2019-05-29 08:15:51,775 (Z-Wave): TX_Session_Layer : Send (repeat count=1) Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x85, 0x02, 0x02], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x33)' request (callback ID=0x33). DEBUG 2019-05-29 08:15:51,775 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x0A, 0x00, 0x13, 0x33, 0x03, 0x85, 0x02, 0x02, 0x05, 0x33, 0x65]. DEBUG 2019-05-29 08:15:51,791 (Z-Wave): RX_Session_Layer : Removed function from pending transaction list (size='0') : ZW_SendData(NodeID=51, Payload=[0x85, 0x02, 0x01], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x32) DEBUG 2019-05-29 08:15:51,791 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06] DEBUG 2019-05-29 08:15:51,791 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x0A, 0x00, 0x13, 0x33, 0x03, 0x85, 0x02, 0x02, 0x05, 0x33, 0x65] transmission OK. DEBUG 2019-05-29 08:15:51,791 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x85, 0x02, 0x02], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x33)' has been successfully sent - waiting 5 000 [ms] for response frame. DEBUG 2019-05-29 08:15:51,791 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:51,807 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x04, 0x01, 0x13, 0x01, 0xE8] DEBUG 2019-05-29 08:15:51,807 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] has been received. DEBUG 2019-05-29 08:15:51,807 (Z-Wave): RX_Session_Layer : 'ZW_SendData' response [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] with status 'RETURN_VALUE_TRUE' received (callback ID=0x33). DEBUG 2019-05-29 08:15:51,807 (Z-Wave): RX_Session_Layer : Waiting 64 982 [ms] for 'ZW_SendData' callback frame (callback ID=0x33). DEBUG 2019-05-29 08:15:51,853 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:51,853 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x05, 0x00, 0x13, 0x33, 0x00, 0xDA] DEBUG 2019-05-29 08:15:51,853 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x05, 0x00, 0x13, 0x33, 0x00, 0xDA] has been received. DEBUG 2019-05-29 08:15:51,853 (Z-Wave): RX_Session_Layer : Callback [0x01, 0x05, 0x00, 0x13, 0x33, 0x00, 0xDA] (callback ID=0x33) with state 'TRANSMIT_COMPLETE_OK' received -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x85, 0x02, 0x02], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x33)' successfully executed. DEBUG 2019-05-29 08:15:51,869 (Z-Wave): RX_Session_Layer : Add function to pending transaction list (size='1') : ZW_SendData(NodeID=51, Payload=[0x85, 0x02, 0x02], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x33) DEBUG 2019-05-29 08:15:51,900 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:51,900 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x0B, 0x00, 0x04, 0x00, 0x33, 0x05, 0x85, 0x03, 0x02, 0x05, 0x00, 0x47] DEBUG 2019-05-29 08:15:51,900 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x0B, 0x00, 0x04, 0x00, 0x33, 0x05, 0x85, 0x03, 0x02, 0x05, 0x00, 0x47] has been received. DEBUG 2019-05-29 08:15:51,900 (Z-Wave): Association_Reader : Node '51' : [COMMAND_CLASS_ASSOCIATION_V2:ASSOCIATION_GET (Retry='1'), GroupID='2', [Association Group : ID='2', Capacitiy='5' []]] succeeded. DEBUG 2019-05-29 08:15:51,900 (Z-Wave): Association_Reader : Node '51' : [COMMAND_CLASS_ASSOCIATION_V2:ASSOCIATION_GET (Retry='1'), GroupID='3' ]... DEBUG 2019-05-29 08:15:51,900 (Z-Wave): Controller_API : Enqueue (WORKING-Queue, Count=1) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x85, 0x02, 0x03], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:51,900 (Z-Wave): Controller_API : Dequeue (WORKING-Queue, Count=0) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x85, 0x02, 0x03], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:51,900 (Z-Wave): RX_Session_Layer : Removed function from pending transaction list (size='0') : ZW_SendData(NodeID=51, Payload=[0x85, 0x02, 0x02], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x33) DEBUG 2019-05-29 08:15:51,900 (Z-Wave): TX_Session_Layer : Executing Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x85, 0x02, 0x03], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'... DEBUG 2019-05-29 08:15:51,900 (Z-Wave): TX_Session_Layer : Send (repeat count=1) Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x85, 0x02, 0x03], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x34)' request (callback ID=0x34). DEBUG 2019-05-29 08:15:51,900 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x0A, 0x00, 0x13, 0x33, 0x03, 0x85, 0x02, 0x03, 0x05, 0x34, 0x63]. DEBUG 2019-05-29 08:15:51,916 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06] DEBUG 2019-05-29 08:15:51,916 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x0A, 0x00, 0x13, 0x33, 0x03, 0x85, 0x02, 0x03, 0x05, 0x34, 0x63] transmission OK. DEBUG 2019-05-29 08:15:51,916 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x85, 0x02, 0x03], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x34)' has been successfully sent - waiting 5 000 [ms] for response frame. DEBUG 2019-05-29 08:15:51,916 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:51,916 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x04, 0x01, 0x13, 0x01, 0xE8] DEBUG 2019-05-29 08:15:51,916 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] has been received. DEBUG 2019-05-29 08:15:51,916 (Z-Wave): RX_Session_Layer : 'ZW_SendData' response [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] with status 'RETURN_VALUE_TRUE' received (callback ID=0x34). DEBUG 2019-05-29 08:15:51,916 (Z-Wave): RX_Session_Layer : Waiting 64 984 [ms] for 'ZW_SendData' callback frame (callback ID=0x34). DEBUG 2019-05-29 08:15:51,994 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:51,994 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x05, 0x00, 0x13, 0x34, 0x00, 0xDD] DEBUG 2019-05-29 08:15:51,994 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x05, 0x00, 0x13, 0x34, 0x00, 0xDD] has been received. DEBUG 2019-05-29 08:15:51,994 (Z-Wave): RX_Session_Layer : Callback [0x01, 0x05, 0x00, 0x13, 0x34, 0x00, 0xDD] (callback ID=0x34) with state 'TRANSMIT_COMPLETE_OK' received -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x85, 0x02, 0x03], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x34)' successfully executed. DEBUG 2019-05-29 08:15:51,994 (Z-Wave): RX_Session_Layer : Add function to pending transaction list (size='1') : ZW_SendData(NodeID=51, Payload=[0x85, 0x02, 0x03], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x34) DEBUG 2019-05-29 08:15:52,041 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:52,041 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x0B, 0x00, 0x04, 0x00, 0x33, 0x05, 0x85, 0x03, 0x03, 0x01, 0x00, 0x42] DEBUG 2019-05-29 08:15:52,041 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x0B, 0x00, 0x04, 0x00, 0x33, 0x05, 0x85, 0x03, 0x03, 0x01, 0x00, 0x42] has been received. DEBUG 2019-05-29 08:15:52,041 (Z-Wave): Association_Reader : Node '51' : [COMMAND_CLASS_ASSOCIATION_V2:ASSOCIATION_GET (Retry='1'), GroupID='3', [Association Group : ID='3', Capacitiy='1' []]] succeeded. DEBUG 2019-05-29 08:15:52,041 (Z-Wave): Node_Initializer : Node '51:0' : COMMAND_CLASS_ASSOCIATION - Read association group information succeeded (Retry='1'). DEBUG 2019-05-29 08:15:52,041 (Z-Wave): RX_Session_Layer : Removed function from pending transaction list (size='0') : ZW_SendData(NodeID=51, Payload=[0x85, 0x02, 0x03], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x34) DEBUG 2019-05-29 08:15:52,041 (Z-Wave): Node_Initializer : Node '51' : ------ Update static data of : [COMMAND_CLASS_MULTI_CHANNEL_ASSOCIATION_V2] DEBUG 2019-05-29 08:15:52,041 (Z-Wave): Node_Initializer : Node '51:0' : COMMAND_CLASS_MULTI_INSTANCE_ASSOCIATION - Read association group information (Retry='1'). DEBUG 2019-05-29 08:15:52,041 (Z-Wave): Association_Reader : Node '51' : [COMMAND_CLASS_MULTI_CHANNEL_ASSOCIATION_V2:MULTI_INSTANCE_ASSOCIATION_GROUPINGS_GET (Retry='1')]... DEBUG 2019-05-29 08:15:52,041 (Z-Wave): Controller_API : Enqueue (WORKING-Queue, Count=1) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x8E, 0x05], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:52,041 (Z-Wave): Controller_API : Dequeue (WORKING-Queue, Count=0) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x8E, 0x05], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:52,041 (Z-Wave): TX_Session_Layer : Executing Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x8E, 0x05], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'... DEBUG 2019-05-29 08:15:52,041 (Z-Wave): TX_Session_Layer : Send (repeat count=1) Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x8E, 0x05], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x35)' request (callback ID=0x35). DEBUG 2019-05-29 08:15:52,041 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x09, 0x00, 0x13, 0x33, 0x02, 0x8E, 0x05, 0x05, 0x35, 0x6F]. DEBUG 2019-05-29 08:15:52,057 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06] DEBUG 2019-05-29 08:15:52,057 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x09, 0x00, 0x13, 0x33, 0x02, 0x8E, 0x05, 0x05, 0x35, 0x6F] transmission OK. DEBUG 2019-05-29 08:15:52,057 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x8E, 0x05], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x35)' has been successfully sent - waiting 5 000 [ms] for response frame. DEBUG 2019-05-29 08:15:52,057 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:52,057 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x04, 0x01, 0x13, 0x01, 0xE8] DEBUG 2019-05-29 08:15:52,057 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] has been received. DEBUG 2019-05-29 08:15:52,057 (Z-Wave): RX_Session_Layer : 'ZW_SendData' response [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] with status 'RETURN_VALUE_TRUE' received (callback ID=0x35). DEBUG 2019-05-29 08:15:52,057 (Z-Wave): RX_Session_Layer : Waiting 64 983 [ms] for 'ZW_SendData' callback frame (callback ID=0x35). DEBUG 2019-05-29 08:15:52,119 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:52,119 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x05, 0x00, 0x13, 0x35, 0x00, 0xDC] DEBUG 2019-05-29 08:15:52,119 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x05, 0x00, 0x13, 0x35, 0x00, 0xDC] has been received. DEBUG 2019-05-29 08:15:52,119 (Z-Wave): RX_Session_Layer : Callback [0x01, 0x05, 0x00, 0x13, 0x35, 0x00, 0xDC] (callback ID=0x35) with state 'TRANSMIT_COMPLETE_OK' received -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x8E, 0x05], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x35)' successfully executed. DEBUG 2019-05-29 08:15:52,119 (Z-Wave): RX_Session_Layer : Add function to pending transaction list (size='1') : ZW_SendData(NodeID=51, Payload=[0x8E, 0x05], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x35) DEBUG 2019-05-29 08:15:52,166 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:52,166 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x09, 0x00, 0x04, 0x00, 0x33, 0x03, 0x8E, 0x06, 0x02, 0x48] DEBUG 2019-05-29 08:15:52,166 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x09, 0x00, 0x04, 0x00, 0x33, 0x03, 0x8E, 0x06, 0x02, 0x48] has been received. DEBUG 2019-05-29 08:15:52,166 (Z-Wave): Association_Reader : Node '51' : [COMMAND_CLASS_MULTI_CHANNEL_ASSOCIATION_V2:MULTI_INSTANCE_ASSOCIATION_GROUPINGS_GET (Retry='1'), NumberOfGroups='2'] succeeded. DEBUG 2019-05-29 08:15:52,166 (Z-Wave): Association_Reader : Node '51' : [COMMAND_CLASS_MULTI_CHANNEL_ASSOCIATION_V2:MULTI_INSTANCE_ASSOCIATION_GET (Retry='1'), GroupID='1' ]... DEBUG 2019-05-29 08:15:52,166 (Z-Wave): RX_Session_Layer : Removed function from pending transaction list (size='0') : ZW_SendData(NodeID=51, Payload=[0x8E, 0x05], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x35) DEBUG 2019-05-29 08:15:52,182 (Z-Wave): Controller_API : Dequeue (WORKING-Queue, Count=0) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x8E, 0x02, 0x01], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:52,182 (Z-Wave): Controller_API : Enqueue (WORKING-Queue, Count=1) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x8E, 0x02, 0x01], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:52,182 (Z-Wave): TX_Session_Layer : Executing Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x8E, 0x02, 0x01], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'... DEBUG 2019-05-29 08:15:52,182 (Z-Wave): TX_Session_Layer : Send (repeat count=1) Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x8E, 0x02, 0x01], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x36)' request (callback ID=0x36). DEBUG 2019-05-29 08:15:52,182 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x0A, 0x00, 0x13, 0x33, 0x03, 0x8E, 0x02, 0x01, 0x05, 0x36, 0x68]. DEBUG 2019-05-29 08:15:52,197 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06] DEBUG 2019-05-29 08:15:52,197 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x0A, 0x00, 0x13, 0x33, 0x03, 0x8E, 0x02, 0x01, 0x05, 0x36, 0x68] transmission OK. DEBUG 2019-05-29 08:15:52,197 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x8E, 0x02, 0x01], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x36)' has been successfully sent - waiting 5 000 [ms] for response frame. DEBUG 2019-05-29 08:15:52,197 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:52,197 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x04, 0x01, 0x13, 0x01, 0xE8] DEBUG 2019-05-29 08:15:52,197 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] has been received. DEBUG 2019-05-29 08:15:52,197 (Z-Wave): RX_Session_Layer : 'ZW_SendData' response [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] with status 'RETURN_VALUE_TRUE' received (callback ID=0x36). DEBUG 2019-05-29 08:15:52,197 (Z-Wave): RX_Session_Layer : Waiting 64 984 [ms] for 'ZW_SendData' callback frame (callback ID=0x36). DEBUG 2019-05-29 08:15:52,260 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:52,260 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x05, 0x00, 0x13, 0x36, 0x00, 0xDF] DEBUG 2019-05-29 08:15:52,260 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x05, 0x00, 0x13, 0x36, 0x00, 0xDF] has been received. DEBUG 2019-05-29 08:15:52,260 (Z-Wave): RX_Session_Layer : Callback [0x01, 0x05, 0x00, 0x13, 0x36, 0x00, 0xDF] (callback ID=0x36) with state 'TRANSMIT_COMPLETE_OK' received -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x8E, 0x02, 0x01], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x36)' successfully executed. DEBUG 2019-05-29 08:15:52,260 (Z-Wave): RX_Session_Layer : Add function to pending transaction list (size='1') : ZW_SendData(NodeID=51, Payload=[0x8E, 0x02, 0x01], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x36) DEBUG 2019-05-29 08:15:52,307 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:52,307 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x0B, 0x00, 0x04, 0x00, 0x33, 0x05, 0x8E, 0x03, 0x01, 0x05, 0x00, 0x4F] DEBUG 2019-05-29 08:15:52,307 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x0B, 0x00, 0x04, 0x00, 0x33, 0x05, 0x8E, 0x03, 0x01, 0x05, 0x00, 0x4F] has been received. DEBUG 2019-05-29 08:15:52,307 (Z-Wave): Association_Reader : Node '51' : [COMMAND_CLASS_MULTI_CHANNEL_ASSOCIATION_V2:MULTI_INSTANCE_ASSOCIATION_GET (Retry='1'), GroupID='1', [Association Group : ID='1', Capacitiy='5' []]] succeeded. DEBUG 2019-05-29 08:15:52,307 (Z-Wave): Association_Reader : Node '51' : [COMMAND_CLASS_MULTI_CHANNEL_ASSOCIATION_V2:MULTI_INSTANCE_ASSOCIATION_GET (Retry='1'), GroupID='2' ]... DEBUG 2019-05-29 08:15:52,307 (Z-Wave): Controller_API : Enqueue (WORKING-Queue, Count=1) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x8E, 0x02, 0x02], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:52,307 (Z-Wave): Controller_API : Dequeue (WORKING-Queue, Count=0) Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x8E, 0x02, 0x02], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'. DEBUG 2019-05-29 08:15:52,307 (Z-Wave): TX_Session_Layer : Executing Z-Wave function call 'ZW_SendData(NodeID=51, Payload=[0x8E, 0x02, 0x02], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x00)'... DEBUG 2019-05-29 08:15:52,307 (Z-Wave): TX_Session_Layer : Send (repeat count=1) Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x8E, 0x02, 0x02], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x37)' request (callback ID=0x37). DEBUG 2019-05-29 08:15:52,307 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x0A, 0x00, 0x13, 0x33, 0x03, 0x8E, 0x02, 0x02, 0x05, 0x37, 0x6A]. DEBUG 2019-05-29 08:15:52,307 (Z-Wave): RX_Session_Layer : Removed function from pending transaction list (size='0') : ZW_SendData(NodeID=51, Payload=[0x8E, 0x02, 0x01], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x36) DEBUG 2019-05-29 08:15:52,322 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06] DEBUG 2019-05-29 08:15:52,322 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x0A, 0x00, 0x13, 0x33, 0x03, 0x8E, 0x02, 0x02, 0x05, 0x37, 0x6A] transmission OK. DEBUG 2019-05-29 08:15:52,322 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x8E, 0x02, 0x02], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x37)' has been successfully sent - waiting 5 000 [ms] for response frame. DEBUG 2019-05-29 08:15:52,322 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:52,322 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x04, 0x01, 0x13, 0x01, 0xE8] DEBUG 2019-05-29 08:15:52,322 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] has been received. DEBUG 2019-05-29 08:15:52,322 (Z-Wave): RX_Session_Layer : 'ZW_SendData' response [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] with status 'RETURN_VALUE_TRUE' received (callback ID=0x37). DEBUG 2019-05-29 08:15:52,322 (Z-Wave): RX_Session_Layer : Waiting 64 982 [ms] for 'ZW_SendData' callback frame (callback ID=0x37). DEBUG 2019-05-29 08:15:52,385 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:52,400 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x05, 0x00, 0x13, 0x37, 0x00, 0xDE] DEBUG 2019-05-29 08:15:52,400 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x05, 0x00, 0x13, 0x37, 0x00, 0xDE] has been received. DEBUG 2019-05-29 08:15:52,400 (Z-Wave): RX_Session_Layer : Callback [0x01, 0x05, 0x00, 0x13, 0x37, 0x00, 0xDE] (callback ID=0x37) with state 'TRANSMIT_COMPLETE_OK' received -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x8E, 0x02, 0x02], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x37)' successfully executed. DEBUG 2019-05-29 08:15:52,400 (Z-Wave): RX_Session_Layer : Add function to pending transaction list (size='1') : ZW_SendData(NodeID=51, Payload=[0x8E, 0x02, 0x02], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x37) DEBUG 2019-05-29 08:15:52,432 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:52,447 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x0B, 0x00, 0x04, 0x00, 0x33, 0x05, 0x8E, 0x03, 0x02, 0x05, 0x00, 0x4C] DEBUG 2019-05-29 08:15:52,447 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x0B, 0x00, 0x04, 0x00, 0x33, 0x05, 0x8E, 0x03, 0x02, 0x05, 0x00, 0x4C] has been received. DEBUG 2019-05-29 08:15:52,447 (Z-Wave): Association_Reader : Node '51' : [COMMAND_CLASS_MULTI_CHANNEL_ASSOCIATION_V2:MULTI_INSTANCE_ASSOCIATION_GET (Retry='1'), GroupID='2', [Association Group : ID='2', Capacitiy='5' []]] succeeded. DEBUG 2019-05-29 08:15:52,463 (Z-Wave): Node_Initializer : Node '51:0' : COMMAND_CLASS_MULTI_INSTANCE_ASSOCIATION - Read association group information succeeded (Retry='1'). DEBUG 2019-05-29 08:15:52,478 (Z-Wave): Node_Initializer : Node '51' : ------ Update static data of : [COMMAND_CLASS_MANUFACTURER_SPECIFIC] DEBUG 2019-05-29 08:15:52,478 (Z-Wave): Node_Initializer : Node '51' : ------ Update static data of : [COMMAND_CLASS_CONFIGURATION] DEBUG 2019-05-29 08:15:52,478 (Z-Wave): Node_Initializer : Node '51' : ------ Update static data of : [COMMAND_CLASS_VERSION] DEBUG 2019-05-29 08:15:52,478 (Z-Wave): Node_Initializer : Node '51' : ------ Update static data of : [COMMAND_CLASS_BASIC] DEBUG 2019-05-29 08:15:52,478 (Z-Wave): Node_Initializer : Node '51' : ------ Update static data of : [COMMAND_CLASS_SENSOR_MULTILEVEL] DEBUG 2019-05-29 08:15:52,478 (Z-Wave): Node_Initializer : Node '51:3' : [COMMAND_CLASS_SENSOR_MULTILEVEL::SENSOR_MULTILEVEL_GET (Retry='1')] DEBUG 2019-05-29 08:15:52,478 (Z-Wave): RX_Session_Layer : Removed function from pending transaction list (size='0') : ZW_SendData(NodeID=51, Payload=[0x8E, 0x02, 0x02], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x37) DEBUG 2019-05-29 08:15:52,478 (Z-Wave): Controller_API : Enqueue (WORKING-Queue, Count=1) Z-Wave function call 'org.openremote.protocol.zwave.model.commandclasses.CCMultiChannelV2FuncDecorator@1792f7d4'. DEBUG 2019-05-29 08:15:52,494 (Z-Wave): Controller_API : Dequeue (WORKING-Queue, Count=0) Z-Wave function call 'org.openremote.protocol.zwave.model.commandclasses.CCMultiChannelV2FuncDecorator@1792f7d4'. DEBUG 2019-05-29 08:15:52,494 (Z-Wave): TX_Session_Layer : Executing Z-Wave function call 'org.openremote.protocol.zwave.model.commandclasses.CCMultiChannelV2FuncDecorator@1792f7d4'... DEBUG 2019-05-29 08:15:52,494 (Z-Wave): TX_Session_Layer : Send (repeat count=1) Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x31, 0x04], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x38)' request (callback ID=0x38). DEBUG 2019-05-29 08:15:52,494 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x0D, 0x00, 0x13, 0x33, 0x06, 0x60, 0x0D, 0x00, 0x03, 0x31, 0x04, 0x05, 0x38, 0xB2]. DEBUG 2019-05-29 08:15:52,510 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06] DEBUG 2019-05-29 08:15:52,510 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] DEBUG 2019-05-29 08:15:52,525 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x0D, 0x00, 0x13, 0x33, 0x06, 0x60, 0x0D, 0x00, 0x03, 0x31, 0x04, 0x05, 0x38, 0xB2] transmission OK. DEBUG 2019-05-29 08:15:52,525 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x31, 0x04], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x38)' has been successfully sent - waiting 5 000 [ms] for response frame. DEBUG 2019-05-29 08:15:52,541 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] has been received. DEBUG 2019-05-29 08:15:52,541 (Z-Wave): RX_Session_Layer : 'ZW_SendData' response [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] with status 'RETURN_VALUE_TRUE' received (callback ID=0x38). DEBUG 2019-05-29 08:15:52,541 (Z-Wave): RX_Session_Layer : Waiting 64 953 [ms] for 'ZW_SendData' callback frame (callback ID=0x38). DEBUG 2019-05-29 08:15:52,557 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:52,557 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x05, 0x00, 0x13, 0x38, 0x00, 0xD1] DEBUG 2019-05-29 08:15:52,557 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x05, 0x00, 0x13, 0x38, 0x00, 0xD1] has been received. DEBUG 2019-05-29 08:15:52,557 (Z-Wave): RX_Session_Layer : Callback [0x01, 0x05, 0x00, 0x13, 0x38, 0x00, 0xD1] (callback ID=0x38) with state 'TRANSMIT_COMPLETE_OK' received -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x31, 0x04], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x38)' successfully executed. DEBUG 2019-05-29 08:15:52,557 (Z-Wave): RX_Session_Layer : Add function to pending transaction list (size='1') : org.openremote.protocol.zwave.model.commandclasses.CCMultiChannelV2FuncDecorator@1792f7d4 DEBUG 2019-05-29 08:15:52,603 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:52,603 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x12, 0x00, 0x04, 0x00, 0x33, 0x0C, 0x60, 0x0D, 0x03, 0x00, 0x31, 0x05, 0x01, 0x44, 0x00, 0x00, 0x08, 0x72, 0xB3] DEBUG 2019-05-29 08:15:52,603 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x12, 0x00, 0x04, 0x00, 0x33, 0x0C, 0x60, 0x0D, 0x03, 0x00, 0x31, 0x05, 0x01, 0x44, 0x00, 0x00, 0x08, 0x72, 0xB3] has been received. DEBUG 2019-05-29 08:15:52,603 (Z-Wave): Node_Initializer : Node '51:3' : [COMMAND_CLASS_SENSOR_MULTILEVEL::SENSOR_MULTILEVEL_REPORT (Retry='1'), Value='21,62', Type='AIR_TEMPERATURE', Scale='AIR_TEMPERATURE_SCALE_CELSIUS']. DEBUG 2019-05-29 08:15:52,603 (Z-Wave): Node_Initializer : Node '51' : ------ Update static data of : [COMMAND_CLASS_SENSOR_BINARY] DEBUG 2019-05-29 08:15:52,603 (Z-Wave): Node_Initializer : Node '51' : ------ Update static data of : [COMMAND_CLASS_SENSOR_ALARM] DEBUG 2019-05-29 08:15:52,603 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_SENSOR_ALARM::SENSOR_ALARM_SUPPORTED_GET (Retry='1')] DEBUG 2019-05-29 08:15:52,619 (Z-Wave): Controller_API : Enqueue (WORKING-Queue, Count=1) Z-Wave function call 'org.openremote.protocol.zwave.model.commandclasses.CCMultiChannelV2FuncDecorator@2c327f7d'. DEBUG 2019-05-29 08:15:52,619 (Z-Wave): Controller_API : Dequeue (WORKING-Queue, Count=0) Z-Wave function call 'org.openremote.protocol.zwave.model.commandclasses.CCMultiChannelV2FuncDecorator@2c327f7d'. DEBUG 2019-05-29 08:15:52,619 (Z-Wave): TX_Session_Layer : Executing Z-Wave function call 'org.openremote.protocol.zwave.model.commandclasses.CCMultiChannelV2FuncDecorator@2c327f7d'... DEBUG 2019-05-29 08:15:52,619 (Z-Wave): TX_Session_Layer : Send (repeat count=1) Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x9C, 0x03], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x39)' request (callback ID=0x39). DEBUG 2019-05-29 08:15:52,619 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x0D, 0x00, 0x13, 0x33, 0x06, 0x60, 0x0D, 0x00, 0x02, 0x9C, 0x03, 0x05, 0x39, 0x18]. DEBUG 2019-05-29 08:15:52,619 (Z-Wave): RX_Session_Layer : Removed function from pending transaction list (size='0') : org.openremote.protocol.zwave.model.commandclasses.CCMultiChannelV2FuncDecorator@1792f7d4 DEBUG 2019-05-29 08:15:52,635 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06] DEBUG 2019-05-29 08:15:52,635 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x0D, 0x00, 0x13, 0x33, 0x06, 0x60, 0x0D, 0x00, 0x02, 0x9C, 0x03, 0x05, 0x39, 0x18] transmission OK. DEBUG 2019-05-29 08:15:52,635 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x9C, 0x03], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x39)' has been successfully sent - waiting 5 000 [ms] for response frame. DEBUG 2019-05-29 08:15:52,635 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:52,635 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x04, 0x01, 0x13, 0x01, 0xE8] DEBUG 2019-05-29 08:15:52,635 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] has been received. DEBUG 2019-05-29 08:15:52,635 (Z-Wave): RX_Session_Layer : 'ZW_SendData' response [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] with status 'RETURN_VALUE_TRUE' received (callback ID=0x39). DEBUG 2019-05-29 08:15:52,635 (Z-Wave): RX_Session_Layer : Waiting 64 979 [ms] for 'ZW_SendData' callback frame (callback ID=0x39). DEBUG 2019-05-29 08:15:52,697 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:52,697 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x05, 0x00, 0x13, 0x39, 0x00, 0xD0] DEBUG 2019-05-29 08:15:52,697 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x05, 0x00, 0x13, 0x39, 0x00, 0xD0] has been received. DEBUG 2019-05-29 08:15:52,697 (Z-Wave): RX_Session_Layer : Callback [0x01, 0x05, 0x00, 0x13, 0x39, 0x00, 0xD0] (callback ID=0x39) with state 'TRANSMIT_COMPLETE_OK' received -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x9C, 0x03], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x39)' successfully executed. DEBUG 2019-05-29 08:15:52,697 (Z-Wave): RX_Session_Layer : Add function to pending transaction list (size='1') : org.openremote.protocol.zwave.model.commandclasses.CCMultiChannelV2FuncDecorator@2c327f7d ERROR 2019-05-29 08:15:57,713 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_SENSOR_ALARM::SENSOR_ALARM_SUPPORTED_GET (Retry='1')] failed : 'COMMAND_CLASS_REPORT_TIMEOUT_ERROR' DEBUG 2019-05-29 08:15:57,713 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_SENSOR_ALARM::SENSOR_ALARM_SUPPORTED_GET (Retry='2')] DEBUG 2019-05-29 08:15:57,713 (Z-Wave): Controller_API : Enqueue (WORKING-Queue, Count=1) Z-Wave function call 'org.openremote.protocol.zwave.model.commandclasses.CCMultiChannelV2FuncDecorator@663bcb18'. DEBUG 2019-05-29 08:15:57,713 (Z-Wave): Controller_API : Dequeue (WORKING-Queue, Count=0) Z-Wave function call 'org.openremote.protocol.zwave.model.commandclasses.CCMultiChannelV2FuncDecorator@663bcb18'. DEBUG 2019-05-29 08:15:57,713 (Z-Wave): TX_Session_Layer : Executing Z-Wave function call 'org.openremote.protocol.zwave.model.commandclasses.CCMultiChannelV2FuncDecorator@663bcb18'... DEBUG 2019-05-29 08:15:57,713 (Z-Wave): TX_Session_Layer : Send (repeat count=1) Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x9C, 0x03], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x3A)' request (callback ID=0x3A). DEBUG 2019-05-29 08:15:57,713 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x0D, 0x00, 0x13, 0x33, 0x06, 0x60, 0x0D, 0x00, 0x02, 0x9C, 0x03, 0x05, 0x3A, 0x1B]. DEBUG 2019-05-29 08:15:57,728 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06] DEBUG 2019-05-29 08:15:57,728 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x0D, 0x00, 0x13, 0x33, 0x06, 0x60, 0x0D, 0x00, 0x02, 0x9C, 0x03, 0x05, 0x3A, 0x1B] transmission OK. DEBUG 2019-05-29 08:15:57,728 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x9C, 0x03], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x3A)' has been successfully sent - waiting 5 000 [ms] for response frame. DEBUG 2019-05-29 08:15:57,744 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:57,744 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x04, 0x01, 0x13, 0x01, 0xE8] DEBUG 2019-05-29 08:15:57,744 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] has been received. DEBUG 2019-05-29 08:15:57,744 (Z-Wave): RX_Session_Layer : 'ZW_SendData' response [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] with status 'RETURN_VALUE_TRUE' received (callback ID=0x3A). DEBUG 2019-05-29 08:15:57,744 (Z-Wave): RX_Session_Layer : Waiting 64 980 [ms] for 'ZW_SendData' callback frame (callback ID=0x3A). DEBUG 2019-05-29 08:15:57,744 (Z-Wave): RX_Session_Layer : Removed function from pending transaction list (size='0') : org.openremote.protocol.zwave.model.commandclasses.CCMultiChannelV2FuncDecorator@2c327f7d DEBUG 2019-05-29 08:15:57,775 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:15:57,775 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x05, 0x00, 0x13, 0x3A, 0x00, 0xD3] DEBUG 2019-05-29 08:15:57,775 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x05, 0x00, 0x13, 0x3A, 0x00, 0xD3] has been received. DEBUG 2019-05-29 08:15:57,791 (Z-Wave): RX_Session_Layer : Callback [0x01, 0x05, 0x00, 0x13, 0x3A, 0x00, 0xD3] (callback ID=0x3A) with state 'TRANSMIT_COMPLETE_OK' received -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x9C, 0x03], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x3A)' successfully executed. DEBUG 2019-05-29 08:15:57,791 (Z-Wave): RX_Session_Layer : Add function to pending transaction list (size='1') : org.openremote.protocol.zwave.model.commandclasses.CCMultiChannelV2FuncDecorator@663bcb18 ERROR 2019-05-29 08:16:02,807 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_SENSOR_ALARM::SENSOR_ALARM_SUPPORTED_GET (Retry='2')] failed : 'COMMAND_CLASS_REPORT_TIMEOUT_ERROR' DEBUG 2019-05-29 08:16:02,807 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_SENSOR_ALARM::SENSOR_ALARM_SUPPORTED_GET (Retry='3')] DEBUG 2019-05-29 08:16:02,807 (Z-Wave): Controller_API : Enqueue (WORKING-Queue, Count=1) Z-Wave function call 'org.openremote.protocol.zwave.model.commandclasses.CCMultiChannelV2FuncDecorator@30fddc39'. DEBUG 2019-05-29 08:16:02,807 (Z-Wave): Controller_API : Dequeue (WORKING-Queue, Count=0) Z-Wave function call 'org.openremote.protocol.zwave.model.commandclasses.CCMultiChannelV2FuncDecorator@30fddc39'. DEBUG 2019-05-29 08:16:02,807 (Z-Wave): TX_Session_Layer : Executing Z-Wave function call 'org.openremote.protocol.zwave.model.commandclasses.CCMultiChannelV2FuncDecorator@30fddc39'... DEBUG 2019-05-29 08:16:02,807 (Z-Wave): TX_Session_Layer : Send (repeat count=1) Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x9C, 0x03], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x3B)' request (callback ID=0x3B). DEBUG 2019-05-29 08:16:02,807 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x0D, 0x00, 0x13, 0x33, 0x06, 0x60, 0x0D, 0x00, 0x02, 0x9C, 0x03, 0x05, 0x3B, 0x1A]. DEBUG 2019-05-29 08:16:02,838 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06] DEBUG 2019-05-29 08:16:02,838 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] DEBUG 2019-05-29 08:16:02,838 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x0D, 0x00, 0x13, 0x33, 0x06, 0x60, 0x0D, 0x00, 0x02, 0x9C, 0x03, 0x05, 0x3B, 0x1A] transmission OK. DEBUG 2019-05-29 08:16:02,838 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x9C, 0x03], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x3B)' has been successfully sent - waiting 5 000 [ms] for response frame. DEBUG 2019-05-29 08:16:02,838 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] has been received. DEBUG 2019-05-29 08:16:02,838 (Z-Wave): RX_Session_Layer : 'ZW_SendData' response [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] with status 'RETURN_VALUE_TRUE' received (callback ID=0x3B). DEBUG 2019-05-29 08:16:02,838 (Z-Wave): RX_Session_Layer : Waiting 64 972 [ms] for 'ZW_SendData' callback frame (callback ID=0x3B). DEBUG 2019-05-29 08:16:02,838 (Z-Wave): RX_Session_Layer : Removed function from pending transaction list (size='0') : org.openremote.protocol.zwave.model.commandclasses.CCMultiChannelV2FuncDecorator@663bcb18 DEBUG 2019-05-29 08:16:02,869 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:16:02,869 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x05, 0x00, 0x13, 0x3B, 0x00, 0xD2] DEBUG 2019-05-29 08:16:02,869 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x05, 0x00, 0x13, 0x3B, 0x00, 0xD2] has been received. DEBUG 2019-05-29 08:16:02,869 (Z-Wave): RX_Session_Layer : Callback [0x01, 0x05, 0x00, 0x13, 0x3B, 0x00, 0xD2] (callback ID=0x3B) with state 'TRANSMIT_COMPLETE_OK' received -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x9C, 0x03], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x3B)' successfully executed. DEBUG 2019-05-29 08:16:02,885 (Z-Wave): RX_Session_Layer : Add function to pending transaction list (size='1') : org.openremote.protocol.zwave.model.commandclasses.CCMultiChannelV2FuncDecorator@30fddc39 ERROR 2019-05-29 08:16:07,885 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_SENSOR_ALARM::SENSOR_ALARM_SUPPORTED_GET (Retry='3')] failed : 'COMMAND_CLASS_REPORT_TIMEOUT_ERROR' DEBUG 2019-05-29 08:16:07,885 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_SENSOR_ALARM::SENSOR_ALARM_SUPPORTED_GET (Retry='4')] DEBUG 2019-05-29 08:16:07,885 (Z-Wave): Controller_API : Enqueue (WORKING-Queue, Count=1) Z-Wave function call 'org.openremote.protocol.zwave.model.commandclasses.CCMultiChannelV2FuncDecorator@505f29c'. DEBUG 2019-05-29 08:16:07,885 (Z-Wave): Controller_API : Dequeue (WORKING-Queue, Count=0) Z-Wave function call 'org.openremote.protocol.zwave.model.commandclasses.CCMultiChannelV2FuncDecorator@505f29c'. DEBUG 2019-05-29 08:16:07,885 (Z-Wave): TX_Session_Layer : Executing Z-Wave function call 'org.openremote.protocol.zwave.model.commandclasses.CCMultiChannelV2FuncDecorator@505f29c'... DEBUG 2019-05-29 08:16:07,885 (Z-Wave): TX_Session_Layer : Send (repeat count=1) Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x9C, 0x03], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x3C)' request (callback ID=0x3C). DEBUG 2019-05-29 08:16:07,885 (Z-Wave): TX_Frame_Layer : Send data frame [0x01, 0x0D, 0x00, 0x13, 0x33, 0x06, 0x60, 0x0D, 0x00, 0x02, 0x9C, 0x03, 0x05, 0x3C, 0x1D]. DEBUG 2019-05-29 08:16:07,900 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x06] DEBUG 2019-05-29 08:16:07,900 (Z-Wave): RX_Frame_Layer : ACK -> Data frame [0x01, 0x0D, 0x00, 0x13, 0x33, 0x06, 0x60, 0x0D, 0x00, 0x02, 0x9C, 0x03, 0x05, 0x3C, 0x1D] transmission OK. DEBUG 2019-05-29 08:16:07,900 (Z-Wave): RX_Session_Layer : ACK -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x9C, 0x03], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x3C)' has been successfully sent - waiting 5 000 [ms] for response frame. DEBUG 2019-05-29 08:16:07,900 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:16:07,900 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x04, 0x01, 0x13, 0x01, 0xE8] DEBUG 2019-05-29 08:16:07,900 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] has been received. DEBUG 2019-05-29 08:16:07,900 (Z-Wave): RX_Session_Layer : 'ZW_SendData' response [0x01, 0x04, 0x01, 0x13, 0x01, 0xE8] with status 'RETURN_VALUE_TRUE' received (callback ID=0x3C). DEBUG 2019-05-29 08:16:07,900 (Z-Wave): RX_Session_Layer : Waiting 64 979 [ms] for 'ZW_SendData' callback frame (callback ID=0x3C). DEBUG 2019-05-29 08:16:07,900 (Z-Wave): RX_Session_Layer : Removed function from pending transaction list (size='0') : org.openremote.protocol.zwave.model.commandclasses.CCMultiChannelV2FuncDecorator@30fddc39 DEBUG 2019-05-29 08:16:07,947 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01] DEBUG 2019-05-29 08:16:07,947 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x05, 0x00, 0x13, 0x3C, 0x00, 0xD5] DEBUG 2019-05-29 08:16:07,947 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x05, 0x00, 0x13, 0x3C, 0x00, 0xD5] has been received. DEBUG 2019-05-29 08:16:07,947 (Z-Wave): RX_Session_Layer : Callback [0x01, 0x05, 0x00, 0x13, 0x3C, 0x00, 0xD5] (callback ID=0x3C) with state 'TRANSMIT_COMPLETE_OK' received -> Z-Wave function 'ZW_SendData(NodeID=51, Payload=[0x9C, 0x03], TxOptions=[TRANSMIT_OPTION_AUTO_ROUTE, TRANSMIT_EXPLORE_OPTION_ACK], CallbackID=0x3C)' successfully executed. DEBUG 2019-05-29 08:16:07,947 (Z-Wave): RX_Session_Layer : Add function to pending transaction list (size='1') : org.openremote.protocol.zwave.model.commandclasses.CCMultiChannelV2FuncDecorator@505f29c ERROR 2019-05-29 08:16:12,963 (Z-Wave): Node_Initializer : Node '51' : [COMMAND_CLASS_SENSOR_ALARM::SENSOR_ALARM_SUPPORTED_GET (Retry='4')] failed : 'COMMAND_CLASS_REPORT_TIMEOUT_ERROR' ERROR 2019-05-29 08:16:13,056 (Z-Wave): Node : Node '51' : Failed to initialize node.