Aeon/Aeotec Recessed Door Sensor Gen5 fails

Designer 2.5
1

I posted about this in the OLD Forum in September of last year… no responses. I have new info, but no better result with OpenRemote.

I purchased a Recessed Door Sensor a year ago now and it’s sat on my desk ever since because none of the hubs I had could “see” it’s state change. Everything saw it joined to the network, but the Open or Close status was ignored or treated as an error. I’ve always been assuming it’s because it uses the Security Command set.

Every now and again, after some upgrade or another, I dig it out and Exclude it, Include it and try again. Always the same result til Saturday last… Sept 10th. My SmartThings hub saw it and decided to allow it to work. However, the Z-Stick via OpenRemote still sees the traffic and ignores it.

I’ve since ordered 2 more, and both joined the network fine. Same result, not surprisingly. All the Hubs see the device/traffic, but only the SmartThings hub can interpret the Open / Close traffic.

Again, I suspect this is related to the Security feature set. My mental image is that there’s a Security key each hub “invents” and when a device is joined to that hub, the traffic can only be decoded by the Hub with the matching key.

DEBUG 2016-09-14 16:37:48,998 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01]
DEBUG 2016-09-14 16:37:48,998 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x08, 0x00, 0x04, 0x00, 0x56, 0x02, 0x98]
DEBUG 2016-09-14 16:37:48,999 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x40]
DEBUG 2016-09-14 16:37:48,999 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x7F]
DEBUG 2016-09-14 16:37:48,999 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x08, 0x00, 0x04, 0x00, 0x56, 0x02, 0x98, 0x40, 0x7F] has been received.
DEBUG 2016-09-14 16:37:48,999 (Z-Wave): RX_Session_Layer : Node ‘86’ : [APP_CMD_HANDLER_FRAME : NodeID=‘86’, Status=[RECEIVE_STATUS_TYPE_SINGLE], CommandClass=‘COMMAND_CLASS_SECURITY’, Command=‘0x40’, Parameters: [ - ]]
DEBUG 2016-09-14 16:37:52,148 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x01]
DEBUG 2016-09-14 16:37:52,148 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x08, 0x00, 0x04, 0x00, 0x56, 0x02, 0x98]
DEBUG 2016-09-14 16:37:52,149 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x40]
DEBUG 2016-09-14 16:37:52,149 (Z-Wave): RX_Serial_Port_RXTX : Data bytes read : [0x7F]
DEBUG 2016-09-14 16:37:52,149 (Z-Wave): RX_Frame_Layer : Data frame [0x01, 0x08, 0x00, 0x04, 0x00, 0x56, 0x02, 0x98, 0x40, 0x7F] has been received.
DEBUG 2016-09-14 16:37:52,149 (Z-Wave): RX_Session_Layer : Node ‘86’ : [APP_CMD_HANDLER_FRAME : NodeID=‘86’, Status=[RECEIVE_STATUS_TYPE_SINGLE], CommandClass=‘COMMAND_CLASS_SECURITY’, Command=‘0x40’, Parameters: [ - ]]

I’ve been using multiple Controllers (hubs) for a very long time. It’s the only way I’ve found to make the Automation function as I want it. Every Controller I use has one or more flaws/missing features and combining them works, at the expense of needing multiple UIs.

I need the One Ring to Control them ALL and I’ve always hoped OpenRemote was just that. I always expected a 2nd (or 3rd or 4th, 5th or 6th) Controller (hub) would not only acquire the Network ID, and a list of nodes, but the Security key would be uniform too.

Anyone got any insight into multiple Controllers? Because it is pretty common to have them. Every ZWave remote is Controller, so if you have a Minimote or a 7 button wall Scene Controller, you’ve got the same issue… although it might not be occurring today, once most devices use the Security Command Class, then the Remotes have to fail, right?

2

Could you post the related nodeX.xml file - I want to check if the device has been “securely” included to Z-Wave network.

3

$ cat webapps/controller/zwave/node76.xml

<?xml version="1.0" encoding="UTF-8"?> AEON Labs BASIC_TYPE_ROUTING_SLAVE GENERIC_TYPE_SENSOR_NOTIFICATION SPECIFIC_TYPE_NOTIFICATION_SENSOR false true
4

I’m also including the debug of an ADD of another Recessed Door Sensor (node#86) However, no node86.xml exists as a result.

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

5

The OpenRemote Z-Wave protocol implementation sends the encryption key to the device and waits for a confirmation from the device that the key has been successfully set but the device doesn’t respond. In this case the device cannot be securely added to the network according to the specification.

I’ve tested the secure inclusion with 3 door locks and another sensor device in the past and they all behaved according to the specification. I’ll try to figure out why the Aeon/Aeotec Recessed Door Sensor Gen5 doesn’t respond to the COMMAND_CLASS_SECURITY::SECURITY_KEY_SET command.

ERROR 2016-09-26 10:57:15,947 (Z-Wave): Secure_Inclusion_Manager : Node ‘86’ : [COMMAND_CLASS_SECURITY::SECURITY_KEY_SET, Key=[0x01, 0x02, 0x03, 0x04, 0x05, 0x06, 0x07, 0x08, 0x01, 0x02, 0x03, 0x04, 0x05, 0x06, 0x07, 0x08]] failed : ‘COMMAND_CLASS_REPORT_TIMEOUT_ERROR’.
WARN 2016-09-26 10:57:15,948 (Z-Wave): Inclusion_Manager : Node ‘86’ : The security enabled Z-Wave node has been added to the UNSECURE Z-Wave network because failed to set the network key.

6

Did you find what’s causing this?

7

I eventually got hold of a Aeon/Aeotec Recessed Door Sensor Gen5.

I’ve included it with an inclusion switch (commands : INCLUSION_MODE_ON, INCLUSION_MODE_OFF, INCLUSION_MODE_STATUS) that I’ve placed on a panel and added a status command/sensor (command : STATUS) and it worked like a charm with factory defaults (no parameter configurations were necessary).

I think the problem is that you’ve included the device with the inclusion hardware button of the Z-Stick which doesn’t work for a security enabled device. In case of a security enabled device a security key has to be set IMMEDIATELY after the device has been included to the Z-Wave network but the Z-Stick will never set the security key because it doesn’t know the key. In your case the device behaved correctly and refused to set the security key because the OpenRemote Z-Wave protocol implementation tried to set the key long after the device has been included to the Z-Wave network.

I think the Aeon/Aeotec Recessed Door Sensor Gen5 manual is outright wrong because it describes inclusion as always with the Z-Stick and Minimote which I think will never work for a security enabled device.

8

I have the Include/Exclude “buttons” on my interface and it’s the only way I do includes since adding them, months back. The tedium of stopping OpenRemote, unplugging the Z-Stick, button clicking, plug it back into the computer, restart OpenRemote… has pretty much forever cured me of doing THAT again! :slight_smile:

But I do think you are barking near to the right tree… I’ve included the Recessed Door sensor using SmartThings include FIRST. This is because I’ve owned my first Recessed Door sensor for more than a year and have tried to pair it during that time to every “Hub” I’ve purchased. None worked except SmartThings.

The same Recessed Door sensor has been excluded and re-included multiple times… as is evidenced by my log of device Addresses:
3 (deleted) Aeotec Recessed Door Sensor
7 (deleted) Aeotec Recessed Door Sensor 6/23/2015
35 23 (deleted) Aeotec Recessed Door Sensor 9/1/2015
42 2A (deleted) Aeotec Recessed Door Sensor
76 4C Aeotec Recessed Door Sensor (FrontDoor) 9/6/2016

76 (hex 4C) is the attempt that finally worked to SmartThings. That successful pairing caused me to buy 3 more and indeed they paired to SmartThings first time.

Effectively, you’re saying that Security devices can pair only with ONE Controller?? And that if I again exclude it and re-include it, this time, OpenRemote, INCLUSION_MODE_ON Button with zwave v3, it will pair properly?

That would mean I have the same problem with Aeon’s MultiSensor 6, also a security device, also paired properly (4 of them) to SmartThings, not paired to OpenRemote via the INCLUSION_MODE_ON button successfully.

9

In general a Z-Wave device can only be part of one Z-Wave network that is defined by a Z-Wave Home ID. That means you have to exclude the Door Sensor from the SmartThings Z-Wave network before you can include it to the OpenRemote Z-Wave network.

The Aeon MultiSensor 6 can be included securely and non-secure. Currently there’s a problem with secure inclusion but it works non-secure.

10

To be clear, I have multiple controllers on a SINGLE Home Network. I started by creating a network using a Staples Connect hub and when that quickly ran out of development growth, I purchased a Z-Stick. I created a new network to test some ideas using OpenRemote. At that point I had two networks, but then I merged them and due to clicking-without-thinking, I added the Staples Hub with many devices, to the Z-Stick/OpenRemote network, with just one device. Thus I was able to learn all about removing devices (factory reset) from networks that no longer exist.

Then I purchased a Wink Hub and hacked it, imagining I’d be able to get some additional Lutron Pico features from it… nevermind, that’s been a dead end so far…

Then I added a MiniMote and a Enerwave 7 Button Scene Controller. Neither work with Z-Stick & OpenRemote, but I suspect one day I will get them working. I suspect if I exclude them and include via SmartThings they will work fine, given there’s plenty of evidence online.

Lastly I got the SmartThings. Mostly it was for the items I had long purchased and gave up hoping they’d be supported by “all.” And here I am, continuing to hope that the Recessed Door sensors will work for both the Z-Stick/OpenRemote Hub as well as SmartThings.

Therefore I have 4 hubs (controllers) and 2 Remotes (controllers too) all on a single HomeID.

To rephrase the question… since the Recessed Door Sensor is joined to SmartThings as Secure already, and Z-Stick/OpenRemote can’t include that, do I exclude it and then Include it via Z-Stick/OpenRemote to get a non-secure pairing, followed by discovery with SmartThings (so it speaks non-secure only) ?

I need another Recessed Door Sensor and another MultiSensor 6, and will be ordering them soon… I know historically that including the Recessed Door Sensor to Z-Stic/OpenRemote yields nothing. I’m hoping Zwave V3 is the cure to that.

11

Received my latest Recessed Door Sensor Gen 5 and Included it via the Z-Stick/OpenRemote. It seems to have worked. From the Debug messages, I can see Opens and Closes. However, my custom GUI interface is completely dead now. I’ll open a new Topic on this. Very frustrating.