OpenZWave / open-zwave

a C++ library to control Z-Wave Networks via a USB Z-Wave Controller.
http://www.openzwave.net/
GNU Lesser General Public License v3.0
1.05k stars 915 forks source link

Support COMMAND_CLASS_BARRIER_OPERATOR (Problem with Linear GD00Z-4 garage door opener) #490

Closed bytedreamer closed 5 years ago

bytedreamer commented 9 years ago

I added the Linear GD00Z-4 to my Z-Wave network. The device is recognized, however it won't properly complete the initialization. As long as it is associated with the network, OpenZWave will not finish the initialization routine.

Here is the section of the log that I believe is causing the issue:

2015-03-21 13:32:39.621 Info, Node016, Sending (Query) message (Callback ID=0x00, Expected Reply=0x49) - Request Node Info (Node=16): 0x01, 0x04, 0x00, 0x60, 0x10, 0x8b
2015-03-21 13:32:39.648 Detail, Node016,   Received: 0x01, 0x04, 0x01, 0x60, 0x01, 0x9b
2015-03-21 13:32:39.648 Detail, 
2015-03-21 13:32:39.648 Info, Node016, FUNC_ID_ZW_REQUEST_NODE_INFO Request successful.
2015-03-21 13:32:39.725 Detail, Node016,   Received: 0x01, 0x0b, 0x00, 0x49, 0x84, 0x10, 0x05, 0x04, 0x40, 0x07, 0x72, 0x98, 0x85
2015-03-21 13:32:39.725 Detail, 
2015-03-21 13:32:39.725 Info, Node016, UPDATE_STATE_NODE_INFO_RECEIVED from node 16
2015-03-21 13:32:39.725 Info, Node016,   Optional command classes for node 16:
2015-03-21 13:32:39.725 Info, Node016,     COMMAND_CLASS_MANUFACTURER_SPECIFIC
2015-03-21 13:32:39.725 Info, Node016,   Using Configured Network Key (AddingNode: false KeySet: false)
2015-03-21 13:32:39.725 Info, Node016,     COMMAND_CLASS_SECURITY
2015-03-21 13:32:39.725 Detail, Node016,   Expected2 reply was received
2015-03-21 13:32:39.726 Detail, Node016,   Message transaction complete
2015-03-21 13:32:39.726 Detail, 
2015-03-21 13:32:39.726 Detail, Node016, Removing current message
2015-03-21 13:32:39.726 Detail, Node016, Query Stage Complete (NodeInfo)
2015-03-21 13:32:39.726 Detail, Node016, AdvanceQueries queryPending=0 queryRetries=0 queryStage=SecurityReport live=1
2015-03-21 13:32:39.726 Detail, Node016, QueryStage_SecurityReport
2015-03-21 13:32:39.726 Detail, Node016, Queuing (Security) SecurityCmd_NonceGet (Node=16): 0x01, 0x09, 0x00, 0x13, 0x10, 0x02, 0x98, 0x40, 0x05, 0x10, 0x3a
2015-03-21 13:32:39.726 Detail, 
2015-03-21 13:32:39.726 Info, Node016, Sending (Security) message (Callback ID=0x10, Expected Reply=0x04) - SecurityCmd_NonceGet (Node=16): 0x01, 0x09, 0x00, 0x13, 0x10, 0x02, 0x98, 0x40, 0x05, 0x10, 0x3a
2015-03-21 13:32:39.731 Detail, Node016,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2015-03-21 13:32:39.731 Detail, Node016,   ZW_SEND_DATA delivered to Z-Wave stack
2015-03-21 13:32:39.802 Detail, Node016,   Received: 0x01, 0x05, 0x00, 0x13, 0x10, 0x00, 0xf9
2015-03-21 13:32:39.802 Detail, Node016,   ZW_SEND_DATA Request with callback ID 0x10 received (expected 0x10)
2015-03-21 13:32:39.802 Info, Node016, Request RTT 75 Average Request RTT 70
2015-03-21 13:33:19.728 Detail, 
2015-03-21 13:33:19.728 Info, Node016, Sending (Security) message (Attempt 2, Callback ID=0x11, Expected Reply=0x04) - SecurityCmd_NonceGet (Node=16): 0x01, 0x09, 0x00, 0x13, 0x10, 0x02, 0x98, 0x40, 0x05, 0x11, 0x3b
2015-03-21 13:33:19.733 Detail, Node016,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2015-03-21 13:33:19.733 Detail, Node016,   ZW_SEND_DATA delivered to Z-Wave stack
2015-03-21 13:33:19.767 Detail, Node016,   Received: 0x01, 0x05, 0x00, 0x13, 0x11, 0x00, 0xf8
2015-03-21 13:33:19.767 Detail, Node016,   ZW_SEND_DATA Request with callback ID 0x11 received (expected 0x11)
2015-03-21 13:33:19.768 Info, Node016, Request RTT 39 Average Request RTT 54
2015-03-21 13:33:59.729 Detail, 
2015-03-21 13:33:59.729 Info, Node016, Sending (Security) message (Attempt 3, Callback ID=0x12, Expected Reply=0x04) - SecurityCmd_NonceGet (Node=16): 0x01, 0x09, 0x00, 0x13, 0x10, 0x02, 0x98, 0x40, 0x05, 0x12, 0x38
2015-03-21 13:33:59.734 Detail, Node016,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2015-03-21 13:33:59.734 Detail, Node016,   ZW_SEND_DATA delivered to Z-Wave stack
2015-03-21 13:33:59.769 Detail, Node016,   Received: 0x01, 0x05, 0x00, 0x13, 0x12, 0x00, 0xfb
2015-03-21 13:33:59.769 Detail, Node016,   ZW_SEND_DATA Request with callback ID 0x12 received (expected 0x12)
2015-03-21 13:33:59.769 Info, Node016, Request RTT 39 Average Request RTT 46
2015-03-21 13:34:39.730 Error, Node016, ERROR: Dropping command, expected response not received after 3 attempt(s)
2015-03-21 13:34:39.730 Detail, Node016, Removing current message
Fishwaldo commented 9 years ago

Did you follow https://github.com/OpenZWave/open-zwave/wiki/Adding-Security-Devices-to-OZW

bytedreamer commented 9 years ago

Yes, I already had configured a Yale Door Lock to the Z-Wave network. I placed the device right next to the controller during the inclusion process. The controller is the Aeon S2 USB stick.

When I get a chance, I'll try the inclusion process again and capture the logs.

Fishwaldo commented 9 years ago

The Log Snippet indicates it wasn't included Securely.

bytedreamer commented 9 years ago

K, Thanks. I will include it back tonight and check the logs.

bytedreamer commented 9 years ago

Looks like there is an issue with the secure inclusion process. I'll work to get the latest OZW GitHub code to compile on my laptop. Let me know if you see anything interesting in the logs.

2015-03-23 20:06:11.538 Detail, contrlr, Queuing (Controller) Add Device
2015-03-23 20:06:11.539 Info, Add Device
2015-03-23 20:06:11.539 Detail, contrlr, Queuing (Command) AddDevice: 0x01, 0x05, 0x00, 0x4a, 0x81, 0x8d, 0xbc
2015-03-23 20:06:11.539 Detail, 
2015-03-23 20:06:11.539 Info, contrlr, Sending (Command) message (Callback ID=0x8d, Expected Reply=0x4a) - AddDevice: 0x01, 0x05, 0x00, 0x4a, 0x81, 0x8d, 0xbc
2015-03-23 20:06:11.543 Detail, contrlr,   Received: 0x01, 0x07, 0x00, 0x4a, 0x8d, 0x01, 0x00, 0x00, 0x3e
2015-03-23 20:06:11.543 Detail, 
2015-03-23 20:06:11.543 Info, contrlr, FUNC_ID_ZW_ADD_NODE_TO_NETWORK:
2015-03-23 20:06:11.543 Info, contrlr, ADD_NODE_STATUS_LEARN_READY
2015-03-23 20:06:11.543 Detail, contrlr,   Expected callbackId was received
2015-03-23 20:06:11.543 Detail, contrlr,   Expected reply was received
2015-03-23 20:06:11.543 Detail, contrlr,   Message transaction complete
2015-03-23 20:06:11.543 Detail, 
2015-03-23 20:06:11.543 Detail, contrlr, Removing current message
2015-03-23 20:06:11.543 Info, WriteNextMsg Controller nothing to do
2015-03-23 20:06:50.363 Detail,   Received: 0x01, 0x07, 0x00, 0x4a, 0x8d, 0x02, 0x00, 0x00, 0x3d
2015-03-23 20:06:50.363 Detail, 
2015-03-23 20:06:50.363 Info, FUNC_ID_ZW_ADD_NODE_TO_NETWORK:
2015-03-23 20:06:50.363 Info, ADD_NODE_STATUS_NODE_FOUND
2015-03-23 20:06:50.497 Detail,   Received: 0x01, 0x0d, 0x00, 0x4a, 0x8d, 0x03, 0x11, 0x06, 0x04, 0x40, 0x07, 0x72, 0x98, 0x5a, 0xd2
2015-03-23 20:06:50.497 Detail, 
2015-03-23 20:06:50.497 Info, FUNC_ID_ZW_ADD_NODE_TO_NETWORK:
2015-03-23 20:06:50.497 Info, ADD_NODE_STATUS_ADDING_SLAVE
2015-03-23 20:06:50.497 Info, Adding node ID 17
2015-03-23 20:06:50.497 Detail, contrlr, Queuing (Command) Add Node Stop: 0x01, 0x04, 0x00, 0x4a, 0x05, 0xb4
2015-03-23 20:06:51.497 Detail, 
2015-03-23 20:06:51.497 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x4a) - Add Node Stop: 0x01, 0x04, 0x00, 0x4a, 0x05, 0xb4
2015-03-23 20:06:51.551 Detail, contrlr,   Received: 0x01, 0x07, 0x00, 0x4a, 0x8d, 0x06, 0x11, 0x00, 0x28
2015-03-23 20:06:51.551 Detail, 
2015-03-23 20:06:51.551 Info, contrlr, FUNC_ID_ZW_ADD_NODE_TO_NETWORK:
2015-03-23 20:06:51.551 Info, contrlr, ADD_NODE_STATUS_DONE
2015-03-23 20:06:51.551 Detail, Node017, AdvanceQueries queryPending=0 queryRetries=0 queryStage=None live=1
2015-03-23 20:06:51.551 Detail, Node017, QueryStage_ProtocolInfo
2015-03-23 20:06:51.551 Detail, Node017, Queuing (Query) Get Node Protocol Info (Node=17): 0x01, 0x04, 0x00, 0x41, 0x11, 0xab
2015-03-23 20:06:51.551 Detail, Node017, Queuing (Query) Query Stage Complete (ProtocolInfo)
2015-03-23 20:06:51.551 Info, Initilizing Node. New Node: true (true)
2015-03-23 20:06:51.551 Detail, contrlr,   Expected reply was received
2015-03-23 20:06:51.551 Detail, contrlr,   Message transaction complete
2015-03-23 20:06:51.551 Detail, 
2015-03-23 20:06:51.551 Detail, contrlr, Removing current message
2015-03-23 20:06:51.552 Detail, 
2015-03-23 20:06:51.552 Info, Node017, Sending (Query) message (Callback ID=0x00, Expected Reply=0x41) - Get Node Protocol Info (Node=17): 0x01, 0x04, 0x00, 0x41, 0x11, 0xab
2015-03-23 20:06:51.556 Detail, Node017,   Received: 0x01, 0x09, 0x01, 0x41, 0xd3, 0x9c, 0x00, 0x04, 0x40, 0x07, 0xba
2015-03-23 20:06:51.556 Detail, 
2015-03-23 20:06:51.556 Info, Node017, Received reply to FUNC_ID_ZW_GET_NODE_PROTOCOL_INFO
2015-03-23 20:06:51.556 Info, Node017,   Protocol Info for Node 17:
2015-03-23 20:06:51.556 Info, Node017,     Listening     = true
2015-03-23 20:06:51.556 Info, Node017,     Beaming       = true
2015-03-23 20:06:51.556 Info, Node017,     Routing       = true
2015-03-23 20:06:51.556 Info, Node017,     Max Baud Rate = 40000
2015-03-23 20:06:51.556 Info, Node017,     Version       = 4
2015-03-23 20:06:51.556 Info, Node017,     Security      = false
2015-03-23 20:06:51.556 Info, Node017,   Basic device class    (0x04) - Routing Slave
2015-03-23 20:06:51.556 Info, Node017,   Generic device Class  (0x40) - Entry Control
2015-03-23 20:06:51.556 Info, Node017,   No specific device class defined
2015-03-23 20:06:51.556 Info, Node017,     COMMAND_CLASS_BASIC is not mapped
2015-03-23 20:06:51.556 Info, Node017,   Mandatory Command Classes for Node 17:
2015-03-23 20:06:51.556 Info, Node017,     COMMAND_CLASS_BASIC
2015-03-23 20:06:51.556 Info, Node017,   Mandatory Command Classes controlled by Node 17:
2015-03-23 20:06:51.556 Info, Node017,     None
2015-03-23 20:06:51.556 Detail, Node017,   Expected reply was received
2015-03-23 20:06:51.556 Detail, Node017,   Message transaction complete
2015-03-23 20:06:51.556 Detail, 
2015-03-23 20:06:51.556 Detail, Node017, Removing current message
2015-03-23 20:06:51.557 Detail, Node017, Query Stage Complete (ProtocolInfo)
2015-03-23 20:06:51.557 Detail, Node017, AdvanceQueries queryPending=0 queryRetries=0 queryStage=Probe live=1
2015-03-23 20:06:51.557 Detail, Node017, QueryStage_Probe
2015-03-23 20:06:51.557 Info, Node017, NoOperation::Set - Routing=true
2015-03-23 20:06:51.557 Detail, Node017, Queuing (NoOp) NoOperation_Set (Node=17): 0x01, 0x09, 0x00, 0x13, 0x11, 0x02, 0x00, 0x00, 0x25, 0x8e, 0x5d
2015-03-23 20:06:51.557 Detail, Node017, Queuing (Query) Query Stage Complete (Probe)
2015-03-23 20:06:51.557 Detail, 
2015-03-23 20:06:51.557 Info, Node017, Sending (NoOp) message (Callback ID=0x8e, Expected Reply=0x13) - NoOperation_Set (Node=17): 0x01, 0x09, 0x00, 0x13, 0x11, 0x02, 0x00, 0x00, 0x25, 0x8e, 0x5d
2015-03-23 20:06:51.585 Detail, Node017,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2015-03-23 20:06:51.585 Detail, Node017,   ZW_SEND_DATA delivered to Z-Wave stack
2015-03-23 20:06:52.061 Detail, Node017,   Received: 0x01, 0x05, 0x00, 0x13, 0x8e, 0x00, 0x67
2015-03-23 20:06:52.061 Detail, Node017,   ZW_SEND_DATA Request with callback ID 0x8e received (expected 0x8e)
2015-03-23 20:06:52.061 Info, Node017, Request RTT 504 Average Request RTT 504
2015-03-23 20:06:52.061 Detail, Node017,   Expected reply was received
2015-03-23 20:06:52.061 Detail, Node017,   Message transaction complete
2015-03-23 20:06:52.061 Detail, 
2015-03-23 20:06:52.061 Detail, Node017, Removing current message
2015-03-23 20:06:52.061 Detail, Node017, Query Stage Complete (Probe)
2015-03-23 20:06:52.061 Detail, Node017, AdvanceQueries queryPending=0 queryRetries=0 queryStage=WakeUp live=1
2015-03-23 20:06:52.061 Detail, Node017, QueryStage_WakeUp
2015-03-23 20:06:52.061 Detail, Node017, QueryStage_ManufacturerSpecific1
2015-03-23 20:06:52.062 Detail, Node017, QueryStage_NodeInfo
2015-03-23 20:06:52.062 Detail, Node017, Queuing (Query) Request Node Info (Node=17): 0x01, 0x04, 0x00, 0x60, 0x11, 0x8a
2015-03-23 20:06:52.062 Detail, Node017, Queuing (Query) Query Stage Complete (NodeInfo)
2015-03-23 20:06:52.062 Detail, 
2015-03-23 20:06:52.062 Info, Node017, Sending (Query) message (Callback ID=0x00, Expected Reply=0x49) - Request Node Info (Node=17): 0x01, 0x04, 0x00, 0x60, 0x11, 0x8a
2015-03-23 20:06:52.088 Detail, Node017,   Received: 0x01, 0x04, 0x01, 0x60, 0x01, 0x9b
2015-03-23 20:06:52.088 Detail, 
2015-03-23 20:06:52.088 Info, Node017, FUNC_ID_ZW_REQUEST_NODE_INFO Request successful.
2015-03-23 20:07:32.063 Detail, 
2015-03-23 20:07:32.063 Info, Node017, Sending (Query) message (Attempt 2, Callback ID=0x00, Expected Reply=0x49) - Request Node Info (Node=17): 0x01, 0x04, 0x00, 0x60, 0x11, 0x8a
2015-03-23 20:07:32.068 Detail, Node017,   Received: 0x01, 0x04, 0x01, 0x60, 0x01, 0x9b
2015-03-23 20:07:32.068 Detail, 
2015-03-23 20:07:32.068 Info, Node017, FUNC_ID_ZW_REQUEST_NODE_INFO Request successful.
2015-03-23 20:07:32.144 Detail, Node017,   Received: 0x01, 0x0b, 0x00, 0x49, 0x84, 0x11, 0x05, 0x04, 0x40, 0x07, 0x72, 0x98, 0x84
2015-03-23 20:07:32.144 Detail, 
2015-03-23 20:07:32.144 Info, Node017, UPDATE_STATE_NODE_INFO_RECEIVED from node 17
2015-03-23 20:07:32.144 Info, Node017,   Optional command classes for node 17:
2015-03-23 20:07:32.144 Info, Node017,     COMMAND_CLASS_MANUFACTURER_SPECIFIC
2015-03-23 20:07:32.144 Info, Node017,   Using Scheme0 Network Key for Key Exchange (AddingNode: true KeySet: false)
2015-03-23 20:07:32.144 Info, Node017,     COMMAND_CLASS_SECURITY
2015-03-23 20:07:32.144 Detail, Node017,   Expected reply was received
2015-03-23 20:07:32.144 Detail, Node017,   Message transaction complete
2015-03-23 20:07:32.144 Detail, 
2015-03-23 20:07:32.144 Detail, Node017, Removing current message
2015-03-23 20:07:32.144 Detail, Node017, Query Stage Complete (NodeInfo)
2015-03-23 20:07:32.144 Detail, Node017, AdvanceQueries queryPending=0 queryRetries=0 queryStage=SecurityReport live=1
2015-03-23 20:07:32.144 Detail, Node017, QueryStage_SecurityReport
2015-03-23 20:07:32.144 Detail, Node017, Queuing (Security) SecurityCmd_SchemeGet (Node=17): 0x01, 0x0a, 0x00, 0x13, 0x11, 0x03, 0x98, 0x04, 0x00, 0x25, 0x8f, 0xc2
2015-03-23 20:07:32.144 Detail, 
2015-03-23 20:07:32.144 Info, Node017, Sending (Security) message (Callback ID=0x8f, Expected Reply=0x04) - SecurityCmd_SchemeGet (Node=17): 0x01, 0x0a, 0x00, 0x13, 0x11, 0x03, 0x98, 0x04, 0x00, 0x25, 0x8f, 0xc2
2015-03-23 20:07:32.150 Detail, Node017,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2015-03-23 20:07:32.150 Detail, Node017,   ZW_SEND_DATA delivered to Z-Wave stack
2015-03-23 20:07:32.219 Detail, Node017,   Received: 0x01, 0x05, 0x00, 0x13, 0x8f, 0x00, 0x66
2015-03-23 20:07:32.219 Detail, Node017,   ZW_SEND_DATA Request with callback ID 0x8f received (expected 0x8f)
2015-03-23 20:07:32.219 Info, Node017, Request RTT 74 Average Request RTT 289
2015-03-23 20:08:12.145 Detail, 
2015-03-23 20:08:12.145 Info, Node017, Sending (Security) message (Attempt 2, Callback ID=0x90, Expected Reply=0x04) - SecurityCmd_SchemeGet (Node=17): 0x01, 0x0a, 0x00, 0x13, 0x11, 0x03, 0x98, 0x04, 0x00, 0x25, 0x90, 0xdd
2015-03-23 20:08:12.151 Detail, Node017,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2015-03-23 20:08:12.151 Detail, Node017,   ZW_SEND_DATA delivered to Z-Wave stack
2015-03-23 20:08:12.186 Detail, Node017,   Received: 0x01, 0x05, 0x00, 0x13, 0x90, 0x00, 0x79
2015-03-23 20:08:12.186 Detail, Node017,   ZW_SEND_DATA Request with callback ID 0x90 received (expected 0x90)
2015-03-23 20:08:12.186 Info, Node017, Request RTT 40 Average Request RTT 164
2015-03-23 20:08:52.146 Detail, 
2015-03-23 20:08:52.146 Info, Node017, Sending (Security) message (Attempt 3, Callback ID=0x91, Expected Reply=0x04) - SecurityCmd_SchemeGet (Node=17): 0x01, 0x0a, 0x00, 0x13, 0x11, 0x03, 0x98, 0x04, 0x00, 0x25, 0x91, 0xdc
2015-03-23 20:08:52.152 Detail, Node017,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2015-03-23 20:08:52.152 Detail, Node017,   ZW_SEND_DATA delivered to Z-Wave stack
2015-03-23 20:08:52.187 Detail, Node017,   Received: 0x01, 0x05, 0x00, 0x13, 0x91, 0x00, 0x78
2015-03-23 20:08:52.187 Detail, Node017,   ZW_SEND_DATA Request with callback ID 0x91 received (expected 0x91)
2015-03-23 20:08:52.187 Info, Node017, Request RTT 40 Average Request RTT 102
2015-03-23 20:09:32.147 Error, Node017, ERROR: Dropping command, expected response not received after 3 attempt(s)
2015-03-23 20:09:32.147 Detail, Node017, Removing current message
openzwave-dev-watcher commented 9 years ago

Put the log through the Log Analyser on the homepage. It will tell you if your reaching a timeout for Secure Inclusion.

Fishwaldo commented 9 years ago

Oops. That last comment is from me.

bytedreamer commented 9 years ago

@Fishwaldo I'll try including the device a few more times. What should I do if inclusion still has timeout issues?

Here are the results of the Log Analyser

Fishwaldo commented 9 years ago

You should wait till OZW is fully started up (allnodesqueried* notification) before trying the inclusion. As noted in the errors tab for node 17, it took 54 seconds to do, which is way over the timeout value for secure inclusion.

If this device is like most locks, its just a matter of keep trying till it includes within 10 seconds or so... Hopefully the security rewrite should speed up the inclusion on OZW side, but the 10 second timeout is a device constraint, not OZW.

bytedreamer commented 9 years ago

@Fishwaldo Please reopen this issue. I've tried included the Linear device many times with no luck. To be sure, I have the device a couple of inches of the USB Z-Wave controller. I can debug the code on my laptop to diagnose the issue. Is there anything specific I should look at within the code.

Is there any chance your rewrite of the Security code will fix my issue?

Thanks

Fishwaldo commented 9 years ago

If its taking more than 10 seconds from the AddNode command to the Secure Inclusion starting, then you need to understand why?

The rewrite might help, buts its not ready yet.

If you cant get it to happen in under 10 seconds, there isnt much i can do. The timeout is imposed on the device not OZW.

bytedreamer commented 9 years ago

I’ll try the including the hardware with the Razberry daughter board, http://razberry.z-wave.me/ http://razberry.z-wave.me/. I should have it early next week. I’m curious if there will be any issues with the Z-Way library.

Thanks

On Mar 28, 2015, at 12:05 AM, Justin Hammond notifications@github.com wrote:

If its taking more than 10 seconds from the AddNode command to the Secure Inclusion starting, then you need to understand why?

The rewrite might help, buts its not ready yet.

If you cant get it to happen in under 10 seconds, there isnt much i can do. The timeout is imposed on the device not OZW.

— Reply to this email directly or view it on GitHub https://github.com/OpenZWave/open-zwave/issues/490#issuecomment-87158546.

bytedreamer commented 9 years ago

@Fishwaldo The z-wave.me ZWay library is able to include the garage door opener device on the first attempt.

satzg commented 9 years ago

Can you capture any logs of the controller traffic?

Thanks, Greg

On Apr 1, 2015, at 8:59 AM, Jonathan Horvath wrote:

@Fishwaldo The z-wave.me ZWay library is able to include the garage door opener device on the first attempt.

— Reply to this email directly or view it on GitHub.

!DSPAM:551c07ce273361027123211!

ualex73 commented 9 years ago

the logfile should be in /var/log/razberry.log if I remember correctly.

2015-04-01 17:25 GMT+02:00 satzg notifications@github.com:

Can you capture any logs of the controller traffic?

Thanks, Greg

On Apr 1, 2015, at 8:59 AM, Jonathan Horvath wrote:

@Fishwaldo The z-wave.me ZWay library is able to include the garage door opener device on the first attempt.

— Reply to this email directly or view it on GitHub.

!DSPAM:551c07ce273361027123211!

— Reply to this email directly or view it on GitHub https://github.com/OpenZWave/open-zwave/issues/490#issuecomment-88522302 .

bytedreamer commented 9 years ago

Yes, I will get the logs later today when I get home.

Fishwaldo commented 9 years ago

I'll lay money its just related to timeout issues.

bytedreamer commented 9 years ago

I posted the zwave.me inclusion logs here

Fishwaldo commented 9 years ago

Yeah. It completes the SecureInclusion in about 2-3 seconds.

I'm sure you can get it working with the current OZW, it's just a matter of making sure OZW is idle when you start the inclusion process.

Fishwaldo commented 9 years ago

If zwave.me stores the network key somewhere, and your using the same dongle for OZW and Zwave.me, then you can include it via zwave.me, copy the network key to OZW Options.xml and it should stay associated and encrypted.

Troy-M commented 9 years ago

@bytedreamer I'm having the same problem, did you ever get this working?

bytedreamer commented 9 years ago

@SurfingNinjas I was not able to get the Garge Door opener working with the OpenZwave library. I switched to a different library that supported the device.

Troy-M commented 9 years ago

@Fishwaldo Can we reopen/investigate this? I am having the same issue with a very similar log. After going my own inclusion logs, it appears that open-zwave does not support command class 0x66 (102)(COMMAND_CLASS_BARRIER_OPERATOR) . I would assume that would stop a garage door from ever working with open-zwave, unless I'm missing something?

Fishwaldo commented 9 years ago

Yep - We don't support that CC. Someone would need to figure it out so we could implement it. :)

What other libraries work with this device?

Troy-M commented 9 years ago

@bytedreamer What library did you use to get this working?

bytedreamer commented 9 years ago

@SurfingNinjas The ZWay Lib from Z-Wave.Me supports the Barrier Operator commands. I've been using this library for a few months with no issues with the garage door opener.

gottsman commented 9 years ago

@bytedreamer Can you tell me where you sourced the razberry card? The couple of US stores listed from the razberry site didn't have any in stock. Perhaps they are switching stock to the newer version.

bytedreamer commented 8 years ago

@gottsman I purchased mine from Amazon. Make sure to get the 500 series version.

http://www.amazon.com/Z-Wave-Me/b/ref=bl_dp_s_web_11388845011?ie=UTF8&node=11388845011&field-lbr_brands_browse-bin=Z-Wave.Me

Fishwaldo commented 8 years ago

I just got confirmation that Aeotec are shipping me their new garage door opener, so I can work on this soon.

nechry commented 8 years ago

Nice! I'm also supose to receive one, so I will enable to test from my side.

Troy-M commented 8 years ago

Any update on this?

nechry commented 8 years ago

From my side nothing, I did not receive the GDC

Fishwaldo commented 8 years ago

I have the GDC, but no change to explore the Barrier CC yet

Fishwaldo commented 8 years ago

Some details on the new CC: http://dz.prosyst.com/pdoc/mBS_SH_SDK_8.0/modules/zwave/api/driver/com/prosyst/mbs/services/zwave/commandclasses/CCBarrierOperator.html

nechry commented 8 years ago

hello Justin I receive the GDC, I just wrote the config file https://github.com/jeedom/plugin-openzwave/blob/master/ressources/openzwave/config/aeotec/zw062_garage_door_controller.xml Base on Rev 4 Engineering Spec Not all parameters work, so is a preliminary version. If you need some test let me know

srirams commented 8 years ago

I've created a patch to support BarrierOperator command class based on: https://github.com/dbadia/openhab/commit/eb5a203303d5029ed97941de5abacab4af676608. I just basically copied one of the other classes with some modifications, so it needs to be verified and cleaned up by someone with more expertise....

It works on my Iris/Linear GDC. I am able to open/close the door as well as receive status updates from the tilt sensor. The tilt sensor is also supposed to send out battery levels (or at least updates when the battery is low) which I don't know how. Maybe the "Burglar" field in the Received Alarm report? The GDC also sets the Access Control of the Received Alarm report to 70 when you request an action (eg, open or close) and there is no change from the tilt sensor. Again, I don't know what this means. Possible related to how the GDC will only make two attempts to perform an action before you have to do it manually.

0001-add-BarrierOperator.patch.txt

Fishwaldo commented 8 years ago

Thanks @srirams I've added it to the dev branch, and will add the Signals Support soon as well.

I might also change the ValueID's we export from this CC so we can represent the Opening/Closing/Stopped Events as well.

nechry commented 8 years ago

I try yesterday the @srirams patch. is ok for open and close but don't report events Opening/Closing/Stopped. I do test on Aeon-labs Garage door Controller

Fishwaldo commented 8 years ago

@nechry: yes - those are not supported in @srirams patch, hence why I said I might change the ValueID exported so we can report these. I'll think about the best approach soon. (as a List - or as a new ValueID etc)

openzwave-dev-watcher commented 8 years ago

How can I help fix this?Also, I would like to get the patch to try it out. Thanks.

On Friday, May 13, 2016 at 12:10:42 AM UTC-7, Jean-François Auger wrote:

I try yesterday the @srirams https://github.com/srirams patch. is ok for open and close but don't report events Opening/Closing/Stopped. I do test on Aeon-labs Garage door Controller

— You are receiving this because you commented. Reply to this email directly or view it on GitHub https://github.com/OpenZWave/open-zwave/issues/490#issuecomment-218968128

kb3dow commented 8 years ago

@openzwave-dev-watcher checkout the dev branch by doing (in your open-zwave directory) - git checkout remotes/origin/Dev make -j 4 Then restart your domoticz (from /etc/init.d/domoticz - assuming you did it that way). I just got the garage opener 2 days ago and will try out this fix this weekend.

Fishwaldo commented 8 years ago

Dev branch is only good for playing around at the moment. Lots of other changes in there and it hasn't had a lot of testing.

dtraub commented 8 years ago

@kb3dow any luck with this opener? I am considering testing out dev to get it working as well just curious what your inputs are?

dtraub commented 8 years ago

I have the GD00Z-4 and would like to get it working with the USB gen5 stick

kb3dow commented 8 years ago

@dtraub I couldn't get it (same GD00Z-4) to work. I use Domoticz with an Aeon Z series stick 2 using Debian on an intel NUC box. I was unable to have it learn the device via the browser (both as a switch and as a security device). When I used the Z stick by itself to pair it, it behaved as if it paired (by they way it beeped - a short beep followed by a long beep) - but the opener wouldn't show up in Domoticz. This was with the dev branch. I restarted the domoticz service after recompiling openzwave. I wouldn't think it needs to be recompiled as the lib for openzwave would be referenced at run time.

legrego commented 8 years ago

@kb3dow I also tried @srirams 's patched version on the dev branch with the GD00Z-4, with no luck. I was able to pair the device with my Aeon Z series Gen 5 stick via the ozwcp, but I could not get or set the device status at that point. It would give initial values for state, alarm, etc, but would not change them, or allow me to change them.

The OZW log indicated this error everytime I changed the orientation of the tilt sensor: ApplicationCommandHandler - Unhandled Command Class 66

legrego commented 8 years ago

Ignore my last comment, I had a stale build.

I was able to get the GD00Z-4 working using @srirams patch against master, with just a small configuration change (see c808b74).

I also added a corresponding change to OZWCP at https://github.com/legrego/open-zwave-control-panel/commit/0925251a566a36543e0c6b5cb0b2c1498bddfa68 to support the new command class.

I'm not sure of the best way to integrate this (if we even need to), since the patch is already applied on the dev branch.

ghost commented 8 years ago

I am also trying to get the Linear GD00Z-4 to work. I haven't actually tried it yet, because I'm almost certain it's not being included securely. Log is similar to @bytedreamer -- Today I applied the patches mentioned, both in ozw and ozwcp. The log seems to indicate that the Barrier stuff is successful. However, I don't think secure inclusion is happening. I have the network key set, and recognize it in the log. Device is nearby, and I'm pressing the include button about 1 second after clicking the "Add Device (Secure) -> Go" button. I'm going to post the log, and if anyone sees anything, please let me know what you think.

`2016-07-21 01:05:10.841 Detail, Queuing (Controller) Add Device 2016-07-21 01:05:10.842 Info, Add Device post: key=fun data= size=0 2016-07-21 01:05:10.842 Detail, contrlr, Queuing (Command) ControllerCommand_AddDevice: 0x01, 0x05, 0x00, 0x4a, 0xc1, 0x1a, 0x6b 2016-07-21 01:05:10.842 Detail, Notification: ControllerComand - Starting 2016-07-21 01:05:10.842 Info, Notification: ControllerCommand home d5663088 Event 1 Error 0 2016-07-21 01:05:10.842 Detail, 2016-07-21 01:05:10.842 Info, contrlr, Sending (Command) message (Callback ID=0x1a, Expected Reply=0x4a) - ControllerCommand_AddDevice: 0x01, 0x05, 0x00, 0x4a, 0xc1, 0x1a, 0x6b 2016-07-21 01:05:10.844 Detail, contrlr, Received: 0x01, 0x07, 0x00, 0x4a, 0x1a, 0x01, 0x00, 0x00, 0xa9 2016-07-21 01:05:10.844 Detail, 2016-07-21 01:05:10.844 Info, contrlr, FUNC_ID_ZW_ADD_NODE_TO_NETWORK: 2016-07-21 01:05:10.845 Info, contrlr, ADD_NODE_STATUS_LEARN_READY 2016-07-21 01:05:10.845 Detail, Node001, Expected callbackId was received 2016-07-21 01:05:10.845 Detail, Node001, Expected reply was received 2016-07-21 01:05:10.845 Detail, Node001, Message transaction complete 2016-07-21 01:05:10.845 Detail, 2016-07-21 01:05:10.845 Detail, contrlr, Removing current message 2016-07-21 01:05:10.845 Detail, Notification: ControllerCommand - Waiting 2016-07-21 01:05:10.845 Info, Notification: ControllerCommand home d5663088 Event 4 Error 0 2016-07-21 01:05:23.570 Detail, Received: 0x01, 0x07, 0x00, 0x4a, 0x1a, 0x02, 0x00, 0x00, 0xaa 2016-07-21 01:05:23.570 Detail, 2016-07-21 01:05:23.570 Info, FUNC_ID_ZW_ADD_NODE_TO_NETWORK: 2016-07-21 01:05:23.570 Info, ADD_NODE_STATUS_NODE_FOUND 2016-07-21 01:05:23.570 Detail, Notification: ControllerCommand - InProgress 2016-07-21 01:05:23.570 Info, Notification: ControllerCommand home d5663088 Event 6 Error 0 2016-07-21 01:05:23.781 Detail, Received: 0x01, 0x0f, 0x00, 0x4a, 0x1a, 0x03, 0x09, 0x08, 0x04, 0x40, 0x07, 0x5e, 0x5a, 0x72, 0x73, 0x98, 0x7c 2016-07-21 01:05:23.781 Detail, 2016-07-21 01:05:23.781 Info, FUNC_ID_ZW_ADD_NODE_TO_NETWORK: 2016-07-21 01:05:23.781 Info, ADD_NODE_STATUS_ADDING_SLAVE 2016-07-21 01:05:23.781 Info, Adding node ID 9 - Secure 2016-07-21 01:05:23.781 Detail, Notification: ControllerCommand - InProgress 2016-07-21 01:05:23.781 Info, Notification: ControllerCommand home d5663088 Event 6 Error 0 2016-07-21 01:05:24.977 Detail, Received: 0x01, 0x07, 0x00, 0x4a, 0x1a, 0x05, 0x09, 0x00, 0xa4 2016-07-21 01:05:24.977 Detail, 2016-07-21 01:05:24.977 Info, FUNC_ID_ZW_ADD_NODE_TO_NETWORK: 2016-07-21 01:05:24.977 Info, ADD_NODE_STATUS_PROTOCOL_DONE 2016-07-21 01:05:24.977 Detail, contrlr, Queuing (Command) Add Node Stop: 0x01, 0x04, 0x00, 0x4a, 0x05, 0xb4 2016-07-21 01:05:24.977 Detail, Notification: ControllerCommand - InProgress 2016-07-21 01:05:24.977 Info, Notification: ControllerCommand home d5663088 Event 6 Error 0 2016-07-21 01:05:24.977 Detail, 2016-07-21 01:05:24.977 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x4a) - Add Node Stop: 0x01, 0x04, 0x00, 0x4a, 0x05, 0xb4 2016-07-21 01:05:25.028 Detail, contrlr, Received: 0x01, 0x07, 0x00, 0x4a, 0x1a, 0x06, 0x09, 0x00, 0xa7 2016-07-21 01:05:25.028 Detail, 2016-07-21 01:05:25.028 Info, contrlr, FUNC_ID_ZW_ADD_NODE_TO_NETWORK: 2016-07-21 01:05:25.028 Info, contrlr, ADD_NODE_STATUS_DONE 2016-07-21 01:05:25.028 Info, Node009, Basic device class (0x04) - Routing Slave 2016-07-21 01:05:25.028 Info, Node009, Generic device Class (0x40) - Entry Control 2016-07-21 01:05:25.028 Info, Node009, Specific device class (0x07) - Secure Barrier AddOn 2016-07-21 01:05:25.028 Info, Node009, COMMAND_CLASS_BASIC is not mapped 2016-07-21 01:05:25.028 Info, Node009, Mandatory Command Classes for Node 9: 2016-07-21 01:05:25.028 Info, Node009, COMMAND_CLASS_BASIC 2016-07-21 01:05:25.028 Info, Node009, Mandatory Command Classes controlled by Node 9: 2016-07-21 01:05:25.028 Info, Node009, None 2016-07-21 01:05:25.028 Detail, Node009, Queuing (Security) SecurityCmd_SchemeGet (Node=9): 0x01, 0x0a, 0x00, 0x13, 0x09, 0x03, 0x98, 0x04, 0x00, 0x25, 0x1b, 0x4e 2016-07-21 01:05:25.028 Info, Node009, Optional command classes for node 9: 2016-07-21 01:05:25.028 Info, Node009, COMMAND_CLASS_ZWAVE_PLUS_INFO 2016-07-21 01:05:25.028 Info, Node009, COMMAND_CLASS_DEVICE_RESET_LOCALLY 2016-07-21 01:05:25.028 Info, Node009, COMMAND_CLASS_MANUFACTURER_SPECIFIC 2016-07-21 01:05:25.028 Info, Node009, COMMAND_CLASS_POWERLEVEL 2016-07-21 01:05:25.028 Info, Node009, COMMAND_CLASS_SECURITY (Existing) 2016-07-21 01:05:25.028 Info, Node009, Initilizing Node. New Node: true (true) 2016-07-21 01:05:25.028 Detail, Node006, Expected reply was received 2016-07-21 01:05:25.028 Detail, Node006, Message transaction complete 2016-07-21 01:05:25.028 Detail, 2016-07-21 01:05:25.028 Detail, contrlr, Removing current message 2016-07-21 01:05:25.028 Detail, Node009, Notification: NodeAdded 2016-07-21 01:05:25.028 Info, Notification: Node Added Home d5663088 Node 9 Genre basic Class NO OPERATION Instance 0 Index 0 Type bool 2016-07-21 01:05:25.028 Detail, Node009, Notification: NodeProtocolInfo 2016-07-21 01:05:25.028 Info, Notification: Node Protocol Info Home d5663088 Node 9 Genre basic Class NO OPERATION Instance 0 Index 0 Type bool 2016-07-21 01:05:25.028 Detail, Node009, Notification: ValueAdded 2016-07-21 01:05:25.029 Info, Notification: Value Added Home 0xd5663088 Node 9 Genre basic Class BASIC Instance 1 Index 0 Type byte 2016-07-21 01:05:25.029 Detail, Node009, Notification: ValueAdded 2016-07-21 01:05:25.029 Info, Notification: Value Added Home 0xd5663088 Node 9 Genre system Class ZWAVE PLUS INFO Instance 1 Index 0 Type byte 2016-07-21 01:05:25.029 Detail, Node009, Notification: ValueAdded 2016-07-21 01:05:25.029 Info, Notification: Value Added Home 0xd5663088 Node 9 Genre system Class ZWAVE PLUS INFO Instance 1 Index 1 Type short 2016-07-21 01:05:25.029 Detail, Node009, Notification: ValueAdded 2016-07-21 01:05:25.029 Info, Notification: Value Added Home 0xd5663088 Node 9 Genre system Class ZWAVE PLUS INFO Instance 1 Index 2 Type short 2016-07-21 01:05:25.029 Detail, Node009, Notification: ValueAdded 2016-07-21 01:05:25.029 Info, Notification: Value Added Home 0xd5663088 Node 9 Genre system Class POWERLEVEL Instance 1 Index 0 Type list 2016-07-21 01:05:25.029 Detail, Node009, Notification: ValueAdded 2016-07-21 01:05:25.029 Info, Notification: Value Added Home 0xd5663088 Node 9 Genre system Class POWERLEVEL Instance 1 Index 1 Type byte 2016-07-21 01:05:25.029 Detail, Node009, Notification: ValueAdded 2016-07-21 01:05:25.029 Info, Notification: Value Added Home 0xd5663088 Node 9 Genre system Class POWERLEVEL Instance 1 Index 2 Type button 2016-07-21 01:05:25.029 Detail, Node009, Notification: ValueAdded 2016-07-21 01:05:25.029 Info, Notification: Value Added Home 0xd5663088 Node 9 Genre system Class POWERLEVEL Instance 1 Index 3 Type byte 2016-07-21 01:05:25.029 Detail, Node009, Notification: ValueAdded 2016-07-21 01:05:25.029 Info, Notification: Value Added Home 0xd5663088 Node 9 Genre system Class POWERLEVEL Instance 1 Index 4 Type list 2016-07-21 01:05:25.029 Detail, Node009, Notification: ValueAdded 2016-07-21 01:05:25.029 Info, Notification: Value Added Home 0xd5663088 Node 9 Genre system Class POWERLEVEL Instance 1 Index 5 Type short 2016-07-21 01:05:25.029 Detail, Node009, Notification: ValueAdded 2016-07-21 01:05:25.029 Info, Notification: Value Added Home 0xd5663088 Node 9 Genre system Class POWERLEVEL Instance 1 Index 6 Type button 2016-07-21 01:05:25.029 Detail, Node009, Notification: ValueAdded 2016-07-21 01:05:25.029 Info, Notification: Value Added Home 0xd5663088 Node 9 Genre system Class POWERLEVEL Instance 1 Index 7 Type button 2016-07-21 01:05:25.029 Detail, Node009, Notification: ValueAdded 2016-07-21 01:05:25.029 Info, Notification: Value Added Home 0xd5663088 Node 9 Genre system Class POWERLEVEL Instance 1 Index 8 Type list 2016-07-21 01:05:25.029 Detail, Node009, Notification: ValueAdded 2016-07-21 01:05:25.029 Info, Notification: Value Added Home 0xd5663088 Node 9 Genre system Class POWERLEVEL Instance 1 Index 9 Type short 2016-07-21 01:05:25.029 Detail, Notification: ControllerCommand - Completed 2016-07-21 01:05:25.029 Info, Notification: ControllerCommand home d5663088 Event 7 Error 0 2016-07-21 01:05:25.029 Detail, 2016-07-21 01:05:25.029 Info, Node009, Sending (Security) message (Callback ID=0x1b, Expected Reply=0x04) - SecurityCmd_SchemeGet (Node=9): 0x01, 0x0a, 0x00, 0x13, 0x09, 0x03, 0x98, 0x04, 0x00, 0x25, 0x1b, 0x4e 2016-07-21 01:05:25.155 Detail, Node009, Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8 2016-07-21 01:05:25.155 Detail, Node009, ZW_SEND_DATA delivered to Z-Wave stack 2016-07-21 01:05:25.219 Detail, Node009, Received: 0x01, 0x07, 0x00, 0x13, 0x1b, 0x00, 0x00, 0x13, 0xe3 2016-07-21 01:05:25.219 Detail, Node009, ZW_SEND_DATA Request with callback ID 0x1b received (expected 0x1b) 2016-07-21 01:05:25.219 Info, Node009, Request RTT 190 Average Request RTT 190 2016-07-21 01:05:25.219 Detail, Expected callbackId was received 2016-07-21 01:05:25.302 Detail, Node009, Received: 0x01, 0x09, 0x00, 0x04, 0x00, 0x09, 0x03, 0x98, 0x05, 0x00, 0x65 2016-07-21 01:05:25.302 Detail, 2016-07-21 01:05:25.302 Info, Node009, Response RTT 272 Average Response RTT 272 2016-07-21 01:05:25.302 Info, Node009, Received SecurityCmd_SchemeReport from node 9: 0 2016-07-21 01:05:25.302 Info, Node009, Security scheme agreed. 2016-07-21 01:05:25.302 Detail, Node009, Queuing (Security) SecurityCmd_NetworkKeySet (Node=9): 0x01, 0x19, 0x00, 0x13, 0x09, 0x12, 0x98, 0x06, 0xde, 0xad, 0xbe, 0xef, 0xca, 0xfe, 0xba, 0xbe, 0xaa, 0xbb, 0xcc, 0xdd, 0xee, 0xff, 0x01, 0x02, 0x25, 0x1c, 0x49 2016-07-21 01:05:25.302 Detail, Node009, Expected reply and command class was received 2016-07-21 01:05:25.302 Detail, Node009, Message transaction complete 2016-07-21 01:05:25.302 Detail, 2016-07-21 01:05:25.302 Detail, Node009, Removing current message 2016-07-21 01:05:25.302 Detail, 2016-07-21 01:05:25.302 Info, Node009, Processing (Security) Nonce Request message (Callback ID=0x1c, Expected Reply=0x04) 2016-07-21 01:05:25.302 Info, Node009, Sending (Security) message (Callback ID=0x1c, Expected Reply=0x04) - Nonce_Get(SecurityCmd_NetworkKeySet) - 0x01, 0x09, 0x00, 0x13, 0x09, 0x02, 0x98, 0x40, 0x05, 0x02: 2016-07-21 01:05:25.310 Detail, Node009, Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8 2016-07-21 01:05:25.310 Detail, Node009, ZW_SEND_DATA delivered to Z-Wave stack 2016-07-21 01:05:25.437 Detail, Node009, Received: 0x01, 0x07, 0x00, 0x13, 0x02, 0x00, 0x00, 0x0d, 0xe4 2016-07-21 01:05:25.437 Detail, Node009, ZW_SEND_DATA Request with callback ID 0x02 received (expected 0x02) 2016-07-21 01:05:25.437 Info, Node009, Request RTT 134 Average Request RTT 162 2016-07-21 01:05:25.517 Detail, Node009, Received: 0x01, 0x10, 0x00, 0x04, 0x00, 0x09, 0x0a, 0x98, 0x80, 0xe2, 0x6c, 0x44, 0xc5, 0xed, 0x0f, 0xa8, 0x6f, 0xda 2016-07-21 01:05:25.517 Info, Node009, Received SecurityCmd_NonceReport from node 9 2016-07-21 01:05:25.517 Info, Node001, Setting Up Inclusion Network Key for Secure Communications 2016-07-21 01:05:25.517 Info, Node001, Setting Up Inclusion Network Key for Secure Communications 2016-07-21 01:05:25.517 Info, Node001, Setting Up Inclusion Network Key for Secure Communications 2016-07-21 01:05:25.517 Info, Node001, Setting Up Inclusion Network Key for Secure Communications 2016-07-21 01:05:25.517 Info, Node001, Setting Up Inclusion Network Key for Secure Communications 2016-07-21 01:05:25.517 Info, Node001, Setting Up Inclusion Network Key for Secure Communications 2016-07-21 01:05:25.517 Info, Node001, Setting Up Inclusion Network Key for Secure Communications 2016-07-21 01:05:25.517 Info, Node001, Setting Up Inclusion Network Key for Secure Communications 2016-07-21 01:05:25.517 Info, Node009, Sending (Security) message (Callback ID=0x1d, Expected Reply=0x04) - SecurityCmd_NetworkKeySet (Node=9): 0x01, 0x19, 0x00, 0x13, 0x09, 0x12, 0x98, 0x06, 0xde, 0xad, 0xbe, 0xef, 0xca, 0xfe, 0xba, 0xbe, 0xaa, 0xbb, 0xcc, 0xdd, 0xee, 0xff, 0x01, 0x02, 0x25, 0x1d, 0x48 2016-07-21 01:05:25.530 Detail, Node009, Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8 2016-07-21 01:05:25.530 Detail, Node009, ZW_SEND_DATA delivered to Z-Wave stack 2016-07-21 01:05:26.115 Detail, Node009, Received: 0x01, 0x08, 0x00, 0x04, 0x00, 0x09, 0x02, 0x98, 0x40, 0x20 2016-07-21 01:05:26.115 Info, Node009, Received SecurityCmd_NonceGet from node 9 2016-07-21 01:05:26.115 Info, NONCES: 0xa4, 0x98, 0xa3, 0x56, 0x54, 0xbf, 0xf2, 0xfd 2016-07-21 01:05:26.115 Info, NONCES: 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00 2016-07-21 01:05:26.115 Info, NONCES: 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00 2016-07-21 01:05:26.115 Info, NONCES: 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00 2016-07-21 01:05:26.115 Info, NONCES: 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00 2016-07-21 01:05:26.115 Info, NONCES: 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00 2016-07-21 01:05:26.115 Info, NONCES: 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00 2016-07-21 01:05:26.115 Info, NONCES: 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00 2016-07-21 01:05:26.115 Info, Node009, Sending (Security) message (Callback ID=0x01, Expected Reply=0x04) - Nonce_Report - 0x01, 0x11, 0x00, 0x13, 0x09, 0x0a, 0x98, 0x80, 0xa4, 0x98, 0xa3, 0x56, 0x54, 0xbf, 0xf2, 0xfd, 0x05, 0x01, 0xcf: 2016-07-21 01:05:26.117 Detail, Node009, Received: 0x01, 0x04, 0x01, 0x13, 0x00, 0xe9 2016-07-21 01:05:26.117 Error, Node009, ERROR: ZW_SEND_DATA could not be delivered to Z-Wave stack 2016-07-21 01:05:26.378 Detail, Node009, Received: 0x01, 0x07, 0x00, 0x13, 0x01, 0x00, 0x00, 0x19, 0xf3 2016-07-21 01:05:26.378 Detail, Node009, ZW_SEND_DATA Request with callback ID 0x01 received (expected 0x01) 2016-07-21 01:05:26.378 Info, Node009, Request RTT 1076 Average Request RTT 619 2016-07-21 01:05:35.302 Detail, 2016-07-21 01:05:35.302 Info, NONCES: 0xa4, 0x98, 0xa3, 0x56, 0x54, 0xbf, 0xf2, 0xfd 2016-07-21 01:05:35.302 Info, NONCES: 0xfa, 0x7a, 0x6c, 0x53, 0x15, 0x14, 0xea, 0xe3 2016-07-21 01:05:35.302 Info, NONCES: 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00 2016-07-21 01:05:35.302 Info, NONCES: 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00 2016-07-21 01:05:35.302 Info, NONCES: 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00 2016-07-21 01:05:35.302 Info, NONCES: 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00 2016-07-21 01:05:35.302 Info, NONCES: 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00 2016-07-21 01:05:35.302 Info, NONCES: 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00 2016-07-21 01:05:35.302 Info, Node009, Sending (Security) message (Callback ID=0x01, Expected Reply=0x04) - Nonce_Report - 0x01, 0x11, 0x00, 0x13, 0x09, 0x0a, 0x98, 0x80, 0xfa, 0x7a, 0x6c, 0x53, 0x15, 0x14, 0xea, 0xe3, 0x05, 0x01, 0x55: 2016-07-21 01:05:35.303 Detail, Node009, Notification: Notification - TimeOut 2016-07-21 01:05:35.303 Info, Notification: Notification home d5663088 node 9 Timeout 2016-07-21 01:05:35.310 Detail, Node009, Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8 2016-07-21 01:05:35.310 Detail, Node009, ZW_SEND_DATA delivered to Z-Wave stack 2016-07-21 01:05:35.368 Detail, Node009, Received: 0x01, 0x07, 0x00, 0x13, 0x01, 0x00, 0x00, 0x06, 0xec 2016-07-21 01:05:35.368 Detail, Node009, ZW_SEND_DATA Request with callback ID 0x01 received (expected 0x01) 2016-07-21 01:05:35.368 Info, Node009, Request RTT 65 Average Request RTT 342 2016-07-21 01:05:45.303 Error, Node009, ERROR: Dropping command, expected response not received after 1 attempt(s) 2016-07-21 01:05:45.303 Detail, Node009, Removing current message 2016-07-21 01:05:45.304 Detail, Node009, Notification: Notification - TimeOut 2016-07-21 01:05:45.304 Info, Notification: Notification home d5663088 node 9 Timeout 2016-07-21 01:05:45.304 Detail, Notification: ControllerCommand - Error - Failed 2016-07-21 01:05:45.304 Info, Notification: ControllerCommand home d5663088 Event 3 Error 10

############################ ############################

2016-07-21 01:13:26.702 Detail, Node009, AdvanceQueries queryPending=0 queryRetries=0 queryStage=None live=1 2016-07-21 01:13:26.702 Detail, Node009, QueryStage_ProtocolInfo 2016-07-21 01:13:26.702 Detail, Node009, Queuing (Query) Get Node Protocol Info (Node=9): 0x01, 0x04, 0x00, 0x41, 0x09, 0xb3 2016-07-21 01:13:26.702 Detail, Node009, Queuing (Query) Query Stage Complete (ProtocolInfo) 2016-07-21 01:13:26.702 Detail, 2016-07-21 01:13:26.703 Info, Node009, Sending (Query) message (Callback ID=0x00, Expected Reply=0x41) - Get Node Protocol Info (Node=9): 0x01, 0x04, 0x00, 0x41, 0x09, 0xb3 post: key=node data= size=0 2016-07-21 01:13:26.705 Detail, Node009, Received: 0x01, 0x09, 0x01, 0x41, 0xd3, 0x9c, 0x01, 0x04, 0x40, 0x07, 0xbb 2016-07-21 01:13:26.705 Detail, 2016-07-21 01:13:26.705 Info, Node009, Received reply to FUNC_ID_ZW_GET_NODE_PROTOCOL_INFO 2016-07-21 01:13:26.705 Info, Node009, Protocol Info for Node 9: 2016-07-21 01:13:26.705 Info, Node009, Listening = true 2016-07-21 01:13:26.705 Info, Node009, Beaming = true 2016-07-21 01:13:26.705 Info, Node009, Routing = true 2016-07-21 01:13:26.705 Info, Node009, Max Baud Rate = 40000 2016-07-21 01:13:26.705 Info, Node009, Version = 4 2016-07-21 01:13:26.705 Info, Node009, Security = false 2016-07-21 01:13:26.705 Detail, Node156, Expected reply was received 2016-07-21 01:13:26.705 Detail, Node156, Message transaction complete 2016-07-21 01:13:26.705 Detail, 2016-07-21 01:13:26.705 Detail, Node009, Removing current message 2016-07-21 01:13:26.705 Detail, Node009, Query Stage Complete (ProtocolInfo) 2016-07-21 01:13:26.705 Detail, Node009, AdvanceQueries queryPending=0 queryRetries=0 queryStage=Probe live=1 2016-07-21 01:13:26.705 Detail, Node009, QueryStage_Probe 2016-07-21 01:13:26.705 Info, Node009, NoOperation::Set - Routing=true 2016-07-21 01:13:26.705 Detail, Node009, Queuing (NoOp) NoOperation_Set (Node=9): 0x01, 0x09, 0x00, 0x13, 0x09, 0x02, 0x00, 0x00, 0x25, 0x1e, 0xd5 2016-07-21 01:13:26.705 Detail, Node009, Queuing (Query) Query Stage Complete (Probe) 2016-07-21 01:13:26.705 Detail, 2016-07-21 01:13:26.705 Info, Node009, Sending (NoOp) message (Callback ID=0x1e, Expected Reply=0x13) - NoOperation_Set (Node=9): 0x01, 0x09, 0x00, 0x13, 0x09, 0x02, 0x00, 0x00, 0x25, 0x1e, 0xd5 2016-07-21 01:13:26.713 Detail, Node009, Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8 2016-07-21 01:13:26.713 Detail, Node009, ZW_SEND_DATA delivered to Z-Wave stack 2016-07-21 01:13:26.843 Detail, Node009, Received: 0x01, 0x07, 0x00, 0x13, 0x1e, 0x00, 0x00, 0x0e, 0xfb 2016-07-21 01:13:26.843 Detail, Node009, ZW_SEND_DATA Request with callback ID 0x1e received (expected 0x1e) 2016-07-21 01:13:26.843 Info, Node009, Request RTT 137 Average Request RTT 239 2016-07-21 01:13:26.843 Detail, Expected callbackId was received 2016-07-21 01:13:26.843 Detail, Expected reply was received 2016-07-21 01:13:26.843 Detail, Message transaction complete 2016-07-21 01:13:26.843 Detail, 2016-07-21 01:13:26.843 Detail, Node009, Removing current message 2016-07-21 01:13:26.843 Detail, Node009, Notification: Notification - NoOperation 2016-07-21 01:13:26.843 Info, Notification: Notification home d5663088 node 9 No Operation Message Complete 2016-07-21 01:13:26.843 Detail, Node009, Query Stage Complete (Probe) 2016-07-21 01:13:26.843 Detail, Node009, AdvanceQueries queryPending=0 queryRetries=0 queryStage=WakeUp live=1 2016-07-21 01:13:26.843 Detail, Node009, QueryStage_WakeUp 2016-07-21 01:13:26.843 Detail, Node009, QueryStage_ManufacturerSpecific1 2016-07-21 01:13:26.843 Detail, Node009, Checking for ManufacturerSpecific CC and Requesting values if present on this node 2016-07-21 01:13:26.843 Detail, Node009, Queuing (Query) ManufacturerSpecificCmd_Get (Node=9): 0x01, 0x09, 0x00, 0x13, 0x09, 0x02, 0x72, 0x04, 0x25, 0x1f, 0xa2 2016-07-21 01:13:26.843 Detail, Node009, Queuing (Query) Query Stage Complete (ManufacturerSpecific1) 2016-07-21 01:13:26.843 Detail, 2016-07-21 01:13:26.843 Info, Node009, Sending (Query) message (Callback ID=0x1f, Expected Reply=0x04) - ManufacturerSpecificCmd_Get (Node=9): 0x01, 0x09, 0x00, 0x13, 0x09, 0x02, 0x72, 0x04, 0x25, 0x1f, 0xa2 2016-07-21 01:13:26.851 Detail, Node009, Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8 2016-07-21 01:13:26.851 Detail, Node009, ZW_SEND_DATA delivered to Z-Wave stack 2016-07-21 01:13:26.910 Detail, Node009, Received: 0x01, 0x07, 0x00, 0x13, 0x1f, 0x00, 0x00, 0x06, 0xf2 2016-07-21 01:13:26.910 Detail, Node009, ZW_SEND_DATA Request with callback ID 0x1f received (expected 0x1f) 2016-07-21 01:13:26.910 Info, Node009, Request RTT 66 Average Request RTT 152 2016-07-21 01:13:26.910 Detail, Expected callbackId was received 2016-07-21 01:13:26.989 Detail, Node009, Received: 0x01, 0x0e, 0x00, 0x04, 0x00, 0x09, 0x08, 0x72, 0x05, 0x01, 0x4f, 0x47, 0x44, 0x35, 0x30, 0xcb 2016-07-21 01:13:26.989 Detail, 2016-07-21 01:13:26.989 Info, Node009, Response RTT 145 Average Response RTT 208 2016-07-21 01:13:26.989 Info, Node009, Received manufacturer specific report from node 9: Manufacturer=Linear, Product=Unknown: type=4744, id=3530 2016-07-21 01:13:26.989 Info, Node009, Node Identity Codes: 014f:4744:3530 2016-07-21 01:13:26.989 Detail, Node009, Expected reply and command class was received 2016-07-21 01:13:26.989 Detail, Node009, Message transaction complete 2016-07-21 01:13:26.989 Detail, 2016-07-21 01:13:26.989 Detail, Node009, Removing current message 2016-07-21 01:13:26.989 Detail, Node009, Notification: NodeNaming 2016-07-21 01:13:26.989 Info, Notification: Node Naming Home d5663088 Node 9 Genre basic Class NO OPERATION Instance 0 Index 0 Type bool 2016-07-21 01:13:26.989 Detail, Node009, Query Stage Complete (ManufacturerSpecific1) 2016-07-21 01:13:26.989 Detail, Node009, AdvanceQueries queryPending=0 queryRetries=0 queryStage=NodeInfo live=1 2016-07-21 01:13:26.989 Detail, Node009, QueryStage_NodePlusInfo 2016-07-21 01:13:26.989 Detail, Node009, Queuing (Query) ZWavePlusInfoCmd_Get (Node=9): 0x01, 0x09, 0x00, 0x13, 0x09, 0x02, 0x5e, 0x01, 0x25, 0x20, 0xb4 2016-07-21 01:13:26.989 Detail, Node009, Queuing (Query) Query Stage Complete (NodePlusInfo) 2016-07-21 01:13:26.989 Detail, 2016-07-21 01:13:26.989 Info, Node009, Sending (Query) message (Callback ID=0x20, Expected Reply=0x04) - ZWavePlusInfoCmd_Get (Node=9): 0x01, 0x09, 0x00, 0x13, 0x09, 0x02, 0x5e, 0x01, 0x25, 0x20, 0xb4 2016-07-21 01:13:26.998 Detail, Node009, Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8 2016-07-21 01:13:26.998 Detail, Node009, ZW_SEND_DATA delivered to Z-Wave stack 2016-07-21 01:13:27.126 Detail, Node009, Received: 0x01, 0x07, 0x00, 0x13, 0x20, 0x00, 0x00, 0x0d, 0xc6 2016-07-21 01:13:27.126 Detail, Node009, ZW_SEND_DATA Request with callback ID 0x20 received (expected 0x20) 2016-07-21 01:13:27.126 Info, Node009, Request RTT 137 Average Request RTT 144 2016-07-21 01:13:27.126 Detail, Expected callbackId was received 2016-07-21 01:13:27.209 Detail, Node009, Received: 0x01, 0x0f, 0x00, 0x04, 0x00, 0x09, 0x09, 0x5e, 0x02, 0x01, 0x05, 0x00, 0x0c, 0x06, 0x0c, 0x06, 0xac 2016-07-21 01:13:27.209 Detail, 2016-07-21 01:13:27.209 Info, Node009, Response RTT 221 Average Response RTT 214 2016-07-21 01:13:27.209 Info, Node009, ZWave+ Info Received from Node 9 2016-07-21 01:13:27.209 Info, Node009, Zwave+ Node Type (0x00) - Z-Wave+ node. Mandatory Command Classes: 2016-07-21 01:13:27.210 Info, Node009, NONE 2016-07-21 01:13:27.210 Info, Node009, Zwave+ Device Type (0xc06) - Access Control Sensor. Mandatory Command Classes: 2016-07-21 01:13:27.210 Info, Node009, COMMAND_CLASS_DEVICE_RESET_LOCALLY 2016-07-21 01:13:27.210 Info, Node009, COMMAND_CLASS_ZWAVE_PLUS_INFO 2016-07-21 01:13:27.210 Info, Node009, 0x59 (Not Supported) 2016-07-21 01:13:27.210 Info, Node009, COMMAND_CLASS_MANUFACTURER_SPECIFIC 2016-07-21 01:13:27.210 Info, Node009, COMMAND_CLASS_POWERLEVEL 2016-07-21 01:13:27.210 Info, Node009, COMMAND_CLASS_ASSOCIATION 2016-07-21 01:13:27.210 Info, Node009, COMMAND_CLASS_VERSION 2016-07-21 01:13:27.210 Info, Node009, COMMAND_CLASS_SENSOR_BINARY 2016-07-21 01:13:27.210 Info, Node009, ZWave+ Role Type (0x40) - Always On Slave 2016-07-21 01:13:27.210 Info, Node009, COMMAND_CLASS_DEVICE_RESET_LOCALLY 2016-07-21 01:13:27.210 Detail, Node009, Initial read of value 2016-07-21 01:13:27.210 Detail, Node009, Initial read of value 2016-07-21 01:13:27.210 Detail, Node009, Initial read of value 2016-07-21 01:13:27.210 Detail, Node009, Expected reply and command class was received 2016-07-21 01:13:27.210 Detail, Node009, Message transaction complete 2016-07-21 01:13:27.210 Detail, 2016-07-21 01:13:27.210 Detail, Node009, Removing current message 2016-07-21 01:13:27.210 Detail, Node009, Notification: ValueAdded 2016-07-21 01:13:27.210 Info, Notification: Value Added Home 0xd5663088 Node 9 Genre system Class VERSION Instance 1 Index 0 Type string 2016-07-21 01:13:27.210 Detail, Node009, Notification: ValueAdded 2016-07-21 01:13:27.210 Info, Notification: Value Added Home 0xd5663088 Node 9 Genre system Class VERSION Instance 1 Index 1 Type string 2016-07-21 01:13:27.210 Detail, Node009, Notification: ValueAdded 2016-07-21 01:13:27.210 Info, Notification: Value Added Home 0xd5663088 Node 9 Genre system Class VERSION Instance 1 Index 2 Type string 2016-07-21 01:13:27.210 Detail, Node009, Notification: ValueAdded 2016-07-21 01:13:27.210 Info, Notification: Value Added Home 0xd5663088 Node 9 Genre user Class SENSOR BINARY Instance 1 Index 0 Type bool 2016-07-21 01:13:27.210 Detail, Node009, Notification: ValueChanged 2016-07-21 01:13:27.210 Info, Notification: Value Changed Home 0xd5663088 Node 9 Genre system Class ZWAVE PLUS INFO Instance 1 Index 0 Type byte 2016-07-21 01:13:27.210 Detail, Node009, Notification: ValueChanged 2016-07-21 01:13:27.210 Info, Notification: Value Changed Home 0xd5663088 Node 9 Genre system Class ZWAVE PLUS INFO Instance 1 Index 1 Type short 2016-07-21 01:13:27.210 Detail, Node009, Notification: ValueChanged 2016-07-21 01:13:27.210 Info, Notification: Value Changed Home 0xd5663088 Node 9 Genre system Class ZWAVE PLUS INFO Instance 1 Index 2 Type short 2016-07-21 01:13:27.210 Detail, Node009, Query Stage Complete (NodePlusInfo) 2016-07-21 01:13:27.210 Detail, Node009, AdvanceQueries queryPending=0 queryRetries=0 queryStage=SecurityReport live=1 2016-07-21 01:13:27.210 Detail, Node009, QueryStage_SecurityReport 2016-07-21 01:13:27.210 Detail, Node009, Queuing (Security) SecurityCmd_SupportedGet (Node=9): 0x01, 0x09, 0x00, 0x13, 0x09, 0x02, 0x98, 0x02, 0x25, 0x21, 0x70 2016-07-21 01:13:27.210 Detail, Node009, Queuing (Query) Query Stage Complete (SecurityReport) 2016-07-21 01:13:27.210 Detail, 2016-07-21 01:13:27.210 Info, Node009, Processing (Security) Nonce Request message (Callback ID=0x21, Expected Reply=0x04) 2016-07-21 01:13:27.210 Info, Node009, Sending (Security) message (Callback ID=0x21, Expected Reply=0x04) - Nonce_Get(SecurityCmd_SupportedGet) - 0x01, 0x09, 0x00, 0x13, 0x09, 0x02, 0x98, 0x40, 0x05, 0x02: 2016-07-21 01:13:27.218 Detail, Node009, Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8 2016-07-21 01:13:27.218 Detail, Node009, ZW_SEND_DATA delivered to Z-Wave stack 2016-07-21 01:13:27.344 Detail, Node009, Received: 0x01, 0x07, 0x00, 0x13, 0x02, 0x00, 0x00, 0x0d, 0xe4 2016-07-21 01:13:27.344 Detail, Node009, ZW_SEND_DATA Request with callback ID 0x02 received (expected 0x02) 2016-07-21 01:13:27.344 Info, Node009, Request RTT 134 Average Request RTT 139 2016-07-21 01:13:37.211 Error, Node009, ERROR: Dropping command, expected response not received after 1 attempt(s) 2016-07-21 01:13:37.211 Detail, Node009, Removing current message 2016-07-21 01:13:37.211 Detail, Node009, Notification: Notification - TimeOut 2016-07-21 01:13:37.211 Info, Notification: Notification home d5663088 node 9 Timeout 2016-07-21 01:13:37.211 Detail, Node009, Query Stage Complete (SecurityReport) 2016-07-21 01:13:37.211 Detail, Node009, AdvanceQueries queryPending=0 queryRetries=0 queryStage=ManufacturerSpecific2 live=1 2016-07-21 01:13:37.211 Detail, Node009, QueryStage_Versions 2016-07-21 01:13:37.211 Info, Node009, Requesting Versions 2016-07-21 01:13:37.211 Info, Node009, Requesting Versions for COMMAND_CLASS_NO_OPERATION 2016-07-21 01:13:37.211 Info, Node009, Requesting Versions for COMMAND_CLASS_BASIC 2016-07-21 01:13:37.211 Info, Node009, Requesting Versions for COMMAND_CLASS_SENSOR_BINARY 2016-07-21 01:13:37.211 Info, Node009, Requesting Versions for COMMAND_CLASS_DEVICE_RESET_LOCALLY 2016-07-21 01:13:37.211 Info, Node009, Requesting Versions for COMMAND_CLASS_ZWAVE_PLUS_INFO 2016-07-21 01:13:37.211 Info, Node009, Requesting Versions for COMMAND_CLASS_MANUFACTURER_SPECIFIC 2016-07-21 01:13:37.211 Info, Node009, Requesting Versions for COMMAND_CLASS_POWERLEVEL 2016-07-21 01:13:37.211 Info, Node009, Requesting Versions for COMMAND_CLASS_ASSOCIATION 2016-07-21 01:13:37.211 Info, Node009, Requesting Versions for COMMAND_CLASS_VERSION 2016-07-21 01:13:37.211 Info, Node009, Requesting Versions for COMMAND_CLASS_SECURITY 2016-07-21 01:13:37.211 Detail, Node009, QueryStage_Instances 2016-07-21 01:13:37.211 Info, Node009, Essential node queries are complete 2016-07-21 01:13:37.211 Detail, Node009, QueryStage_Static 2016-07-21 01:13:37.211 Detail, Node009, Queuing (Query) AssociationCmd_GroupingsGet (Node=9): 0x01, 0x09, 0x00, 0x13, 0x09, 0x02, 0x85, 0x05, 0x25, 0x22, 0x69 2016-07-21 01:13:37.212 Detail, Node009, Queuing (Query) VersionCmd_Get (Node=9): 0x01, 0x09, 0x00, 0x13, 0x09, 0x02, 0x86, 0x11, 0x25, 0x23, 0x7f 2016-07-21 01:13:37.212 Detail, Node009, Queuing (Query) Query Stage Complete (Static) 2016-07-21 01:13:37.212 Detail, Node009, Notification: EssentialNodeQueriesComplete 2016-07-21 01:13:37.212 Info, Notification: Essential Node 9 Queries Complete 2016-07-21 01:13:37.212 Detail, 2016-07-21 01:13:37.212 Info, Node009, Sending (Query) message (Callback ID=0x22, Expected Reply=0x04) - AssociationCmd_GroupingsGet (Node=9): 0x01, 0x09, 0x00, 0x13, 0x09, 0x02, 0x85, 0x05, 0x25, 0x22, 0x69 2016-07-21 01:13:37.219 Detail, Node009, Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8 2016-07-21 01:13:37.219 Detail, Node009, ZW_SEND_DATA delivered to Z-Wave stack 2016-07-21 01:13:37.274 Detail, Node009, Received: 0x01, 0x07, 0x00, 0x13, 0x22, 0x00, 0x00, 0x06, 0xcf 2016-07-21 01:13:37.274 Detail, Node009, ZW_SEND_DATA Request with callback ID 0x22 received (expected 0x22) 2016-07-21 01:13:37.274 Info, Node009, Request RTT 62 Average Request RTT 100 2016-07-21 01:13:37.274 Detail, Expected callbackId was received 2016-07-21 01:13:47.212 Error, Node009, ERROR: Dropping command, expected response not received after 1 attempt(s) 2016-07-21 01:13:47.212 Detail, Node009, Removing current message 2016-07-21 01:13:47.212 Detail, Node009, Notification: Notification - TimeOut 2016-07-21 01:13:47.212 Info, Notification: Notification home d5663088 node 9 Timeout 2016-07-21 01:13:47.212 Detail, 2016-07-21 01:13:47.212 Info, Node009, Sending (Query) message (Callback ID=0x23, Expected Reply=0x04) - VersionCmd_Get (Node=9): 0x01, 0x09, 0x00, 0x13, 0x09, 0x02, 0x86, 0x11, 0x25, 0x23, 0x7f 2016-07-21 01:13:47.220 Detail, Node009, Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8 2016-07-21 01:13:47.220 Detail, Node009, ZW_SEND_DATA delivered to Z-Wave stack 2016-07-21 01:13:47.274 Detail, Node009, Received: 0x01, 0x07, 0x00, 0x13, 0x23, 0x00, 0x00, 0x06, 0xce 2016-07-21 01:13:47.274 Detail, Node009, ZW_SEND_DATA Request with callback ID 0x23 received (expected 0x23) 2016-07-21 01:13:47.274 Info, Node009, Request RTT 62 Average Request RTT 81 2016-07-21 01:13:47.275 Detail, Expected callbackId was received 2016-07-21 01:13:57.213 Error, Node009, ERROR: Dropping command, expected response not received after 1 attempt(s) 2016-07-21 01:13:57.213 Detail, Node009, Removing current message 2016-07-21 01:13:57.213 Detail, Node009, Notification: Notification - TimeOut 2016-07-21 01:13:57.213 Info, Notification: Notification home d5663088 node 9 Timeout 2016-07-21 01:13:57.213 Detail, Node009, Query Stage Complete (Static) 2016-07-21 01:13:57.213 Detail, Node009, AdvanceQueries queryPending=0 queryRetries=0 queryStage=Associations live=1 2016-07-21 01:13:57.213 Detail, Node009, QueryStage_Associations 2016-07-21 01:13:57.213 Info, Node009, Number of association groups reported for node 9 is 0. 2016-07-21 01:13:57.213 Info, Node009, Get Associations for group 1 of node 9 2016-07-21 01:13:57.213 Detail, Node009, Queuing (Send) AssociationCmd_Get (Node=9): 0x01, 0x0a, 0x00, 0x13, 0x09, 0x03, 0x85, 0x02, 0x01, 0x25, 0x24, 0x6b 2016-07-21 01:13:57.213 Detail, Node009, Queuing (Query) Query Stage Complete (Associations) 2016-07-21 01:13:57.213 Detail, 2016-07-21 01:13:57.213 Info, Node009, Sending (Send) message (Callback ID=0x24, Expected Reply=0x04) - AssociationCmd_Get (Node=9): 0x01, 0x0a, 0x00, 0x13, 0x09, 0x03, 0x85, 0x02, 0x01, 0x25, 0x24, 0x6b 2016-07-21 01:13:57.220 Detail, Node009, Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8 2016-07-21 01:13:57.220 Detail, Node009, ZW_SEND_DATA delivered to Z-Wave stack 2016-07-21 01:13:57.276 Detail, Node009, Received: 0x01, 0x07, 0x00, 0x13, 0x24, 0x00, 0x00, 0x06, 0xc9 2016-07-21 01:13:57.276 Detail, Node009, ZW_SEND_DATA Request with callback ID 0x24 received (expected 0x24) 2016-07-21 01:13:57.276 Info, Node009, Request RTT 62 Average Request RTT 71 2016-07-21 01:13:57.276 Detail, Expected callbackId was received 2016-07-21 01:14:07.214 Error, Node009, ERROR: Dropping command, expected response not received after 1 attempt(s) 2016-07-21 01:14:07.214 Detail, Node009, Removing current message 2016-07-21 01:14:07.214 Detail, Node009, Notification: Notification - TimeOut 2016-07-21 01:14:07.214 Info, Notification: Notification home d5663088 node 9 Timeout 2016-07-21 01:14:07.214 Detail, Node009, Query Stage Complete (Associations) 2016-07-21 01:14:07.214 Detail, Node009, AdvanceQueries queryPending=0 queryRetries=0 queryStage=Neighbors live=1 2016-07-21 01:14:07.214 Detail, Node009, QueryStage_Neighbors 2016-07-21 01:14:07.214 Detail, Requesting routing info (neighbor list) for Node 9 2016-07-21 01:14:07.214 Detail, Node009, Queuing (Command) Get Routing Info (Node=9): 0x01, 0x07, 0x00, 0x80, 0x09, 0x00, 0x00, 0x03, 0x72 2016-07-21 01:14:07.214 Detail, Node009, Queuing (Query) Query Stage Complete (Neighbors) 2016-07-21 01:14:07.214 Detail, 2016-07-21 01:14:07.214 Info, Node009, Sending (Command) message (Callback ID=0x00, Expected Reply=0x80) - Get Routing Info (Node=9): 0x01, 0x07, 0x00, 0x80, 0x09, 0x00, 0x00, 0x03, 0x72 2016-07-21 01:14:07.218 Detail, Node009, Received: 0x01, 0x20, 0x01, 0x80, 0xc0, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x9e 2016-07-21 01:14:07.218 Detail, 2016-07-21 01:14:07.218 Info, Node009, Received reply to FUNC_ID_ZW_GET_ROUTING_INFO 2016-07-21 01:14:07.218 Info, Node009, Neighbors of this node are: 2016-07-21 01:14:07.218 Info, Node009, Node 7 2016-07-21 01:14:07.218 Info, Node009, Node 8 2016-07-21 01:14:07.218 Detail, Expected reply was received 2016-07-21 01:14:07.218 Detail, Message transaction complete 2016-07-21 01:14:07.218 Detail, 2016-07-21 01:14:07.218 Detail, Node009, Removing current message 2016-07-21 01:14:07.218 Detail, Node009, Query Stage Complete (Neighbors) 2016-07-21 01:14:07.218 Detail, Node009, AdvanceQueries queryPending=0 queryRetries=0 queryStage=Session live=1 2016-07-21 01:14:07.218 Detail, Node009, QueryStage_Session 2016-07-21 01:14:07.218 Detail, Node009, Queuing (Query) PowerlevelCmd_Get (Node=9): 0x01, 0x09, 0x00, 0x13, 0x09, 0x02, 0x73, 0x02, 0x25, 0x25, 0x9f 2016-07-21 01:14:07.218 Detail, Node009, Queuing (Query) Query Stage Complete (Session) 2016-07-21 01:14:07.219 Detail, 2016-07-21 01:14:07.219 Info, Node009, Sending (Query) message (Callback ID=0x25, Expected Reply=0x04) - PowerlevelCmd_Get (Node=9): 0x01, 0x09, 0x00, 0x13, 0x09, 0x02, 0x73, 0x02, 0x25, 0x25, 0x9f 2016-07-21 01:14:07.226 Detail, Node009, Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8 2016-07-21 01:14:07.226 Detail, Node009, ZW_SEND_DATA delivered to Z-Wave stack 2016-07-21 01:14:07.284 Detail, Node009, Received: 0x01, 0x07, 0x00, 0x13, 0x25, 0x00, 0x00, 0x07, 0xc9 2016-07-21 01:14:07.284 Detail, Node009, ZW_SEND_DATA Request with callback ID 0x25 received (expected 0x25) 2016-07-21 01:14:07.284 Info, Node009, Request RTT 65 Average Request RTT 68 2016-07-21 01:14:07.284 Detail, Expected callbackId was received 2016-07-21 01:14:07.369 Detail, Node009, Received: 0x01, 0x0a, 0x00, 0x04, 0x00, 0x09, 0x04, 0x73, 0x03, 0x00, 0x00, 0x8c 2016-07-21 01:14:07.369 Detail, 2016-07-21 01:14:07.369 Info, Node009, Response RTT 150 Average Response RTT 182 2016-07-21 01:14:07.369 Info, Node009, Received a PowerLevel report: PowerLevel=Normal, Timeout=0 2016-07-21 01:14:07.369 Detail, Node009, Initial read of value 2016-07-21 01:14:07.369 Detail, Node009, Initial read of value 2016-07-21 01:14:07.369 Detail, Node009, Expected reply and command class was received 2016-07-21 01:14:07.369 Detail, Node009, Message transaction complete 2016-07-21 01:14:07.369 Detail, 2016-07-21 01:14:07.369 Detail, Node009, Removing current message 2016-07-21 01:14:07.369 Detail, Node009, Notification: ValueChanged 2016-07-21 01:14:07.369 Info, Notification: Value Changed Home 0xd5663088 Node 9 Genre system Class POWERLEVEL Instance 1 Index 0 Type list 2016-07-21 01:14:07.369 Detail, Node009, Notification: ValueChanged 2016-07-21 01:14:07.369 Info, Notification: Value Changed Home 0xd5663088 Node 9 Genre system Class POWERLEVEL Instance 1 Index 1 Type byte 2016-07-21 01:14:07.369 Detail, Node009, Query Stage Complete (Session) 2016-07-21 01:14:07.369 Detail, Node009, AdvanceQueries queryPending=0 queryRetries=0 queryStage=Dynamic live=1 2016-07-21 01:14:07.369 Detail, Node009, QueryStage_Dynamic 2016-07-21 01:14:07.369 Detail, Node009, Queuing (Send) BasicCmd_Get (Node=9): 0x01, 0x09, 0x00, 0x13, 0x09, 0x02, 0x20, 0x02, 0x25, 0x26, 0xcf 2016-07-21 01:14:07.369 Detail, Node009, Queuing (Send) SensorBinaryCmd_Get (Node=9): 0x01, 0x09, 0x00, 0x13, 0x09, 0x02, 0x30, 0x02, 0x25, 0x27, 0xde 2016-07-21 01:14:07.369 Detail, Node009, Queuing (Query) Query Stage Complete (Dynamic) 2016-07-21 01:14:07.369 Detail, 2016-07-21 01:14:07.369 Info, Node009, Sending (Send) message (Callback ID=0x26, Expected Reply=0x04) - BasicCmd_Get (Node=9): 0x01, 0x09, 0x00, 0x13, 0x09, 0x02, 0x20, 0x02, 0x25, 0x26, 0xcf 2016-07-21 01:14:07.378 Detail, Node009, Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8 2016-07-21 01:14:07.378 Detail, Node009, ZW_SEND_DATA delivered to Z-Wave stack 2016-07-21 01:14:07.506 Detail, Node009, Received: 0x01, 0x07, 0x00, 0x13, 0x26, 0x00, 0x00, 0x0d, 0xc0 2016-07-21 01:14:07.506 Detail, Node009, ZW_SEND_DATA Request with callback ID 0x26 received (expected 0x26) 2016-07-21 01:14:07.506 Info, Node009, Request RTT 136 Average Request RTT 102 2016-07-21 01:14:07.506 Detail, Expected callbackId was received 2016-07-21 01:14:17.370 Error, Node009, ERROR: Dropping command, expected response not received after 1 attempt(s) 2016-07-21 01:14:17.371 Detail, Node009, Removing current message 2016-07-21 01:14:17.371 Detail, Node009, Notification: Notification - TimeOut 2016-07-21 01:14:17.371 Info, Notification: Notification home d5663088 node 9 Timeout 2016-07-21 01:14:17.371 Detail, 2016-07-21 01:14:17.371 Info, Node009, Sending (Send) message (Callback ID=0x27, Expected Reply=0x04) - SensorBinaryCmd_Get (Node=9): 0x01, 0x09, 0x00, 0x13, 0x09, 0x02, 0x30, 0x02, 0x25, 0x27, 0xde 2016-07-21 01:14:17.378 Detail, Node009, Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8 2016-07-21 01:14:17.378 Detail, Node009, ZW_SEND_DATA delivered to Z-Wave stack 2016-07-21 01:14:17.433 Detail, Node009, Received: 0x01, 0x07, 0x00, 0x13, 0x27, 0x00, 0x00, 0x06, 0xca 2016-07-21 01:14:17.433 Detail, Node009, ZW_SEND_DATA Request with callback ID 0x27 received (expected 0x27) 2016-07-21 01:14:17.433 Info, Node009, Request RTT 62 Average Request RTT 82 2016-07-21 01:14:17.433 Detail, Expected callbackId was received 2016-07-21 01:14:27.371 Error, Node009, ERROR: Dropping command, expected response not received after 1 attempt(s) 2016-07-21 01:14:27.372 Detail, Node009, Removing current message 2016-07-21 01:14:27.372 Detail, Node009, Notification: Notification - TimeOut 2016-07-21 01:14:27.372 Info, Notification: Notification home d5663088 node 9 Timeout 2016-07-21 01:14:27.372 Detail, Node009, Query Stage Complete (Dynamic) 2016-07-21 01:14:27.372 Detail, Node009, AdvanceQueries queryPending=0 queryRetries=0 queryStage=Configuration live=1 2016-07-21 01:14:27.372 Detail, Node009, QueryStage_Configuration 2016-07-21 01:14:27.372 Detail, Node009, QueryStage_Complete 2016-07-21 01:14:27.372 Warning, CheckCompletedNodeQueries m_allNodesQueried=0 m_awakeNodesQueried=1 2016-07-21 01:14:27.372 Warning, CheckCompletedNodeQueries all=0, deadFound=0 sleepingOnly=1 2016-07-21 01:14:27.372 Detail, Node009, Notification: NodeQueriesComplete 2016-07-21 01:14:27.372 Info, Notification: Node 9 Queries Complete`

Fishwaldo commented 8 years ago

Your Controller is dropping one of the Security Messages, so Secure Inclusion doesn't happen. I'd retry a few times... sometimes RF issues etc can cause this.

tobiebooth commented 8 years ago

I was able to get the GD00Z-4 working with the commits in @legrego's comment. We've also added support for it to Home Assistant (https://github.com/home-assistant/home-assistant/pull/2712) which works great.

Is there any ETA on when this could make it to master so that we have a timeline of availability in Home Assistant?