Secure devices not working after 0.45

cexshun · May 22, 2017, 6:26pm

I copied options.xml which contains my custom NetworkKey over to .homeassistant. Upgraded using the AIO pip3 method. Everything seems to be working, including my unsecured Zwave devices.

However, my 3 zwave devices that I’ve added using add_node_secure are now problematic. The 2 motion sensors are stuck in cacheload mode and are not responding. One being stuck in On and the other in Off. My Schlage Connect is not responding to unlock commands, not get_usercode and set_usercode. Below is the log file from attempting to unlock the Schlage using Zwave,

2017-05-22 13:05:13.447 Info, Node024, Value::Set - COMMAND_CLASS_DOOR_LOCK - Locked - 0 - 1 - False
2017-05-22 13:05:13.448 Info, Node024, Value_Lock::Set - Requesting lock to be Unlocked
2017-05-22 13:05:13.448 Detail, Node024, Queuing (Send) DoorLockCmd_Set (Node=24): 0x01, 0x0a, 0x00, 0x13, 0x18, 0x03, 0x62, 0x01, 0x00, 0x25, 0x99, 0x22
2017-05-22 13:05:13.448 Detail, Node024, Queuing (Send) DoorLockCmd_Get (Node=24): 0x01, 0x09, 0x00, 0x13, 0x18, 0x02, 0x62, 0x02, 0x25, 0x9a, 0x20
2017-05-22 13:05:13.448 Detail,
2017-05-22 13:05:13.448 Info, Node024, Sending (Send) message (Callback ID=0x99, Expected Reply=0x04) - DoorLockCmd_Set (Node=24): 0x01, 0x0a, 0x00, 0x13, 0x18, 0x03, 0x62, 0x01, 0x00, 0x25, 0x99, 0x22
2017-05-22 13:05:13.456 Detail, Node024,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2017-05-22 13:05:13.457 Detail, Node024,   ZW_SEND_DATA delivered to Z-Wave stack
2017-05-22 13:05:14.838 Detail, Node024,   Received: 0x01, 0x07, 0x00, 0x13, 0x99, 0x00, 0x00, 0x8b, 0xf9
2017-05-22 13:05:14.838 Detail, Node024,   ZW_SEND_DATA Request with callback ID 0x99 received (expected 0x99)
2017-05-22 13:05:14.838 Info, Node024, Request RTT 1389 Average Request RTT 1378
2017-05-22 13:05:14.838 Detail,   Expected callbackId was received
2017-05-22 13:05:23.449 Error, Node024, ERROR: Dropping command, expected response not received after 1 attempt(s)
2017-05-22 13:05:23.450 Detail, Node024, Removing current message
2017-05-22 13:05:23.450 Detail, Node024, Notification: Notification - TimeOut
2017-05-22 13:05:23.456 Detail,
2017-05-22 13:05:23.456 Info, Node024, Sending (Send) message (Callback ID=0x9a, Expected Reply=0x04) - DoorLockCmd_Get (Node=24): 0x01, 0x09, 0x00, 0x13, 0x18, 0x02, 0x62, 0x02, 0x25, 0x9a, 0x20
2017-05-22 13:05:23.464 Detail, Node024,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2017-05-22 13:05:23.464 Detail, Node024,   ZW_SEND_DATA delivered to Z-Wave stack
2017-05-22 13:05:24.810 Detail, Node024,   Received: 0x01, 0x07, 0x00, 0x13, 0x9a, 0x00, 0x00, 0x87, 0xf6
2017-05-22 13:05:24.810 Detail, Node024,   ZW_SEND_DATA Request with callback ID 0x9a received (expected 0x9a)
2017-05-22 13:05:24.810 Info, Node024, Request RTT 1353 Average Request RTT 1365
2017-05-22 13:05:24.810 Detail,   Expected callbackId was received

For troubleshooting purposes, I’ve also copied my options.xml directly to /home/homeassistant/.homeassistant/deps/python_openzwave/ozw_config and ran an apt-get update/upgrade. Neither had any effect,

SebasT · May 22, 2017, 6:45pm

Please post the first 20 lines of your OZW log file from you hass config dir

cexshun · May 22, 2017, 6:55pm

2017-05-22 12:55:29.569 Always, OpenZwave Version 1.4.2508 Starting Up
2017-05-22 12:55:42.923 Info, Setting Up Provided Network Key for Secure Communications
2017-05-22 12:55:42.923 Info, mgr,     Added driver for controller /dev/ttyACM0
2017-05-22 12:55:42.924 Info,   Opening controller /dev/ttyACM0
2017-05-22 12:55:42.924 Info, Trying to open serial port /dev/ttyACM0 (attempt 1)
2017-05-22 12:55:42.924 Info, Serial port /dev/ttyACM0 opened (attempt 1)
2017-05-22 12:55:42.925 Detail, contrlr, Queuing (Command) FUNC_ID_ZW_GET_VERSION: 0x01, 0x03, 0x00, 0x15, 0xe9
2017-05-22 12:55:42.925 Detail, contrlr, Queuing (Command) FUNC_ID_ZW_MEMORY_GET_ID: 0x01, 0x03, 0x00, 0x20, 0xdc
2017-05-22 12:55:42.925 Detail, contrlr, Queuing (Command) FUNC_ID_ZW_GET_CONTROLLER_CAPABILITIES: 0x01, 0x03, 0x00, 0x05, 0xf9
2017-05-22 12:55:42.925 Detail, contrlr, Queuing (Command) FUNC_ID_SERIAL_API_GET_CAPABILITIES: 0x01, 0x03, 0x00, 0x07, 0xfb
2017-05-22 12:55:42.925 Detail, contrlr, Queuing (Command) FUNC_ID_ZW_GET_SUC_NODE_ID: 0x01, 0x03, 0x00, 0x56, 0xaa
2017-05-22 12:55:42.925 Detail,
2017-05-22 12:55:42.925 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x15) - FUNC_ID_ZW_GET_VERSION: 0x01, 0x03, 0x00, 0x15, 0xe9
2017-05-22 12:55:42.927 Detail, contrlr,   Received: 0x01, 0x10, 0x01, 0x15, 0x5a, 0x2d, 0x57, 0x61, 0x76, 0x65, 0x20, 0x33, 0x2e, 0x39, 0x35, 0x00, 0x01, 0x99
2017-05-22 12:55:42.927 Detail,
2017-05-22 12:55:42.927 Info, contrlr, Received reply to FUNC_ID_ZW_GET_VERSION:
2017-05-22 12:55:42.927 Info, contrlr,     Static Controller library, version Z-Wave 3.95
2017-05-22 12:55:42.927 Detail, Node045,   Expected reply was received
2017-05-22 12:55:42.927 Detail, Node045,   Message transaction complete
2017-05-22 12:55:42.927 Detail,

SebasT · May 22, 2017, 7:44pm

Line two tells me that a security key (from options.xml) is loaded. Now the question is, is it the right key? By default there’s no key set, so it’s loading a options.xml that you edited. Can you double check if it’s the right key? Maybe you can also search the disk for other options.xml files and see if you accidentally placed the wrong options.xml in your config dir??

cexshun · May 22, 2017, 7:54pm

root@raspberrypi:/# find ./ -type f -name options.xml
./home/homeassistant/.homeassistant/deps/python_openzwave/ozw_config/options.xml
./home/homeassistant/.homeassistant/options.xml
./srv/homeassistant/src/python-openzwave/openzwave/config/options.xml
./srv/homeassistant/homeassistant_venv/lib/python3.4/site-packages/libopenzwave-0.3.2-py3.4-linux-armv7l.egg/config/options.xml

/srv/homeassistant/homeassistant_venv/lib/python3.4/site-packages/libopenzwave-0.3.2-py3.4-linux-armv7l.egg/config/options.xmlm, /home/homeassistant/.homeassistant/deps/python_openzwave/ozw_config/options.xml and /home/homeassistant/.homeassistant/options.xml all have the same key. This key have never changed since my initial install and was generated randomly.

/srv/homeassistant/src/python-openzwave/openzwave/config/options.xml does not have a key.

SebasT · May 22, 2017, 8:16pm

Looking at the info you gave I wouldn’t expect the options.xml or security key to be the problem. I’m guessing it might be a communications issue that just happens to only impact you secure devices. Are these secure devices by any chance far away from your controller? Maybe do a heal network?

cexshun · May 22, 2017, 8:37pm

The lock is within 10 feet and separated by a single wall. The motion sensors are within 20 feet and separated by 2-3 walls.

I did a network heal. While the lock did respond with neighbors, it’s still having the same error. I suppose I can attempt to exclude and pair again when I get home and see if it changes anything.

I attempted to get_usercode which in the past did return a value. But now I’m getting this:

May 22 15:36:27 raspberrypi hass[2317]: INFO:homeassistant.core:Bus:Handling <Event call_service[L]: domain=lock, service_call_id=1977680080-29, service_data=node_id=24, code_slot=1, service=get_usercode>
May 22 15:36:27 raspberrypi hass[2317]: INFO:homeassistant.components.lock.zwave:Usercode at slot 1 is: **********

Not sure if it’s an update or not, but the usercode wasn’t previously censored.

stratotally · June 25, 2017, 2:26am

@cexshun - I’m seeing the same thing. Censored.