Switches unresponsive in HA front-end but work fine in OZWCP

Configuration Z-Wave
, ,
1

I installed HA around version 0.33 and have kept up-to-date until the latest 0.36 release yesterday. I’m running a VirtualEnv setup in a vanilla Debian installation inside a virtual machine (host is Win10 on an i5-6600K CPU with an SSD, so it’s quite fast). I’m using the Aeontec Gen5 ZW090 Z-Stick, and things have mostly been working smoothly. I’ve got about 40 nodes on the network, mostly relay switches, dimmers, and a few fan controls all throughout the house. I have emulated_hue and homebridge set up for integration with both Alexa and Siri, both of which seem to work well. I recently switched from SQLite to MySQL to avoid potential issues with a growing database, and that too is working smoothly.

However, the last couple of weeks, two relay switches have stopped responding to control signals from the web interface. They still report, but trying to change states results in nothing at all. The UI reports the state change request acknowledgement in a dark gray notification, but the state doesn’t change. Running tail -f OZW_Log.txt shows no Z-wave activity at all when I make the request in the browser. No errors appear in home-assistant.log either. In the last few days, another 3-4 switches have stopped responding as well, though they also continue to report when operated manually.

If I stop HA and start OZWCP instead (using the exact same zwcfg_... XML file), these same switches respond immediately through the control panel as expected. Other switches and nodes also still work fine from HA; there seems to be no pattern to the failures, and the problem seems to be specific to HA and not in the Z-wave network or hardware. I’ve tried running a network heal, but the problem remains.

Has anyone else run into this behavior? Does anyone have a recommendation for how to troubleshoot (i.e. extra debug messages, other logs, changed config options, etc.)? I’m at a loss.

1 Like
2

I have been struggling with this for a long time. Restarting HA usually makes things work smoothly again… for awhile.

I really have no suggestions. I am stumped. I assumed the problem was hardware related as I didn’t see anybody else complaining about it, and my posts about it got no responses. But maybe not. There’s at least two of us now.

3

I’ve restarted multiple times, both with and without any configuration tweaks. It doesn’t seem to help on my end. There’s just some inexplicable disconnect between the web UI and the underlying control signal. I’ve even checked with the Chrome network transaction inspector, and the web request does happen without any errors:

General:

Request URL:http://192.168.1.2:8123/api/services/homeassistant/turn_off
Request Method:POST
Status Code:200 OK
Remote Address:192.168.1.2:8123

Response Headers:

Content-Length:2
Content-Type:application/json
Date:Mon, 16 Jan 2017 19:37:58 GMT
Server:Python/3.4 aiohttp/1.2.0

Request Headers:

Accept:*/*
Accept-Encoding:gzip, deflate
Accept-Language:en-US,en;q=0.8
Connection:keep-alive
Content-Length:58
Content-Type:application/json;charset=UTF-8
Host:192.168.1.2:8123
Origin:http://192.168.1.2:8123
Referer:http://192.168.1.2:8123/states/group.rooms
User-Agent:Mozilla/5.0 (Windows NT 10.0; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/55.0.2883.87 Safari/537.36
X-HA-access:

Request Payload

{entity_id: "switch.office_stairwell_lights_switch_53_0"}

The response is a single empty JSON list: []

I’m happy to add debug code to relevant Python files, if it would help. I haven’t figured out where to start that effort. Is it possibly an async IO problem? I saw this mentioned in the changelog for the 0.36 release.

4

Similar behavior here with the 0.36 update. Specifically, Secure Node Schlage locks not responding to commands in the UI. I did remove the node from the network, then added again, to no avail.

  • Debian 8.x
  • Aotec Z-Stick (Gen 5)
  • Schlage BE469NXCEN Zwave

I will be happy to provide more log / config info if needed.

Reverting back to 0.35.1

5

Rolling back to 0.35.1 appears to work for me (possibly relevant for @anderson110), at least on an initial test after letting the Z-wave network get to a ready state. I’m going to try going back to 0.36 with the logger component enabled with full debug output to see what happens.

EDIT: apparently 0.36.1 was just released. I’m updating to that instead of 0.36.0 for the purpose of testing with full logging info.

6

Updating to 0.36.1 appears to have solved the problem. I can say at least that the nodes that were unresponsive in 0.36.0 and some later 0.35.x versions are now responding again. I will leave the logger component enabled at the debug level for another few days in case the problem resurfaces after running for a while.

7

UPDATE: I gave 0.36.1 a try, but still having some trouble with the Schlage SECURE Zwave locks. The UI will intermittently control the lock, for 1 cycle, but after that its a no-go. The locks works just fine under OZWCP, so guessing I will wait for another 0.36.xx update.

8

I am going on 24 hours without any new missed zwave events. Hopeful that this is fixed.

It would be nice if the actual fix could be identified. Maybe I will take a look at the diff.

9

Unfortunately I had more non-responsive behavior today, so my issue is not resolved in 0.36.1.

10

My Schlage is having issues also. Everything works fine in 0.35.3. The lock will always revert to “locked” in HA 0.36 and above. Using the same configuration in both versions, when trying to unlock I found:

openZWAVE logs are identical
HA logs have the JSON parsed differently and a few more Value changed notifications

Could the JSON difference be the issue?

HA 0.35.3
Jan 23 22:18:58 raspberrypi hass[633]: DEBUG:libopenzwave:notif_callback : new notification
Jan 23 22:18:58 raspberrypi hass[633]: DEBUG:libopenzwave:notif_callback : Notification type : 2, nodeId : 2
Jan 23 22:18:58 raspberrypi hass[633]: DEBUG:libopenzwave:addValueId : ValueID : YYYYYYYYYYYYYYYYY
Jan 23 22:18:58 raspberrypi hass[633]: DEBUG:libopenzwave:addValueId : GetCommandClassId : 98, GetType : 4
Jan 23 22:18:58 raspberrypi hass[633]: DEBUG:libopenzwave:addValueId : Notification : {‘valueId’: {‘index’: 1, ‘label’: ‘Locked (Advanced)’, ‘homeId’: XXXXXXXXXX, ‘nodeId’: 2, ‘units’: ‘’, ‘instance’: 1, ‘genre’: ‘User’, ‘commandClass’: ‘COMMAND_CLASS_DOOR_LOCK’, ‘type’: ‘List’, ‘readOnly’: False, ‘id’: YYYYYYYYYYYYYYYYY, ‘value’: ‘Unsecure’}, ‘notificationType’: ‘ValueChanged’, ‘homeId’: XXXXXXXXXX, ‘nodeId’: 2}
Jan 23 22:18:58 raspberrypi hass[633]: DEBUG:libopenzwave:notif_callback : call callback context
Jan 23 22:18:58 raspberrypi hass[633]: DEBUG:openzwave:zwcallback args=[{‘valueId’: {‘index’: 1, ‘label’: ‘Locked (Advanced)’, ‘homeId’: XXXXXXXXXX, ‘nodeId’: 2, ‘units’: ‘’, ‘instance’: 1, ‘genre’: ‘User’, ‘commandClass’: ‘COMMAND_CLASS_DOOR_LOCK’, ‘type’: ‘List’, ‘readOnly’: False, ‘id’: YYYYYYYYYYYYYYYYY, ‘value’: ‘Unsecure’}, ‘notificationType’: ‘ValueChanged’, ‘homeId’: XXXXXXXXXX, ‘nodeId’: 2}]
Jan 23 22:18:58 raspberrypi hass[633]: DEBUG:openzwave:Z-Wave Notification ValueChanged : {‘valueId’: {‘index’: 1, ‘label’: ‘Locked (Advanced)’, ‘homeId’: XXXXXXXXXX, ‘nodeId’: 2, ‘units’: ‘’, ‘instance’: 1, ‘genre’: ‘User’, ‘commandClass’: ‘COMMAND_CLASS_DOOR_LOCK’, ‘type’: ‘List’, ‘readOnly’: False, ‘id’: YYYYYYYYYYYYYYYYY, ‘value’: ‘Unsecure’}, ‘notificationType’: ‘ValueChanged’, ‘homeId’: XXXXXXXXXX, ‘nodeId’: 2}
Jan 23 22:18:58 raspberrypi hass[633]: DEBUG:libopenzwave:notif_callback : end

HA 0.36.1
Jan 23 21:33:08 raspberrypi hass[4272]: DEBUG:libopenzwave:notif_callback : new notification
Jan 23 21:33:08 raspberrypi hass[4272]: DEBUG:libopenzwave:notif_callback : Notification type : 2, nodeId : 2
Jan 23 21:33:08 raspberrypi hass[4272]: DEBUG:libopenzwave:addValueId : ValueID : YYYYYYYYYYYYYYYYY
Jan 23 21:33:08 raspberrypi hass[4272]: DEBUG:libopenzwave:addValueId : GetCommandClassId : 98, GetType : 4
Jan 23 21:33:08 raspberrypi hass[4272]: DEBUG:libopenzwave:addValueId : Notification : {‘nodeId’: 2, ‘notificationType’: ‘ValueChanged’, ‘valueId’: {‘value’: ‘Unsecure’, ‘id’: YYYYYYYYYYYYYYYYY, ‘type’: ‘List’, ‘label’: ‘Locked (Advanced)’, ‘homeId’: XXXXXXXXXX, ‘commandClass’: ‘COMMAND_CLASS_DOOR_LOCK’, ‘instance’: 1, ‘nodeId’: 2, ‘units’: ‘’, ‘readOnly’: False, ‘genre’: ‘User’, ‘index’: 1}, ‘homeId’: XXXXXXXXXX}
Jan 23 21:33:08 raspberrypi hass[4272]: DEBUG:libopenzwave:notif_callback : call callback context
Jan 23 21:33:08 raspberrypi hass[4272]: DEBUG:openzwave:zwcallback args=[{‘nodeId’: 2, ‘notificationType’: ‘ValueChanged’, ‘valueId’: {‘value’: ‘Unsecure’, ‘id’: YYYYYYYYYYYYYYYYY, ‘type’: ‘List’, ‘label’: ‘Locked (Advanced)’, ‘homeId’: XXXXXXXXXX, ‘commandClass’: ‘COMMAND_CLASS_DOOR_LOCK’, ‘instance’: 1, ‘nodeId’: 2, ‘units’: ‘’, ‘readOnly’: False, ‘genre’: ‘User’, ‘index’: 1}, ‘homeId’: XXXXXXXXXX}]
Jan 23 21:33:08 raspberrypi hass[4272]: DEBUG:openzwave:Z-Wave Notification ValueChanged : {‘nodeId’: 2, ‘notificationType’: ‘ValueChanged’, ‘valueId’: {‘value’: ‘Unsecure’, ‘id’: YYYYYYYYYYYYYYYYY, ‘type’: ‘List’, ‘label’: ‘Locked (Advanced)’, ‘homeId’: XXXXXXXXXX, ‘commandClass’: ‘COMMAND_CLASS_DOOR_LOCK’, ‘instance’: 1, ‘nodeId’: 2, ‘units’: ‘’, ‘readOnly’: False, ‘genre’: ‘User’, ‘index’: 1}, ‘homeId’: XXXXXXXXXX}
Jan 23 21:33:08 raspberrypi hass[4272]: DEBUG:homeassistant.components.lock.zwave:Value changed for label Locked
Jan 23 21:33:08 raspberrypi hass[4272]: DEBUG:homeassistant.components.sensor.zwave:Value changed for label Alarm Type
Jan 23 21:33:08 raspberrypi hass[4272]: DEBUG:homeassistant.components.sensor.zwave:Value changed for label Alarm Level
Jan 23 21:33:08 raspberrypi hass[4272]: DEBUG:homeassistant.components.sensor.zwave:Value changed for label SourceNodeId
Jan 23 21:33:08 raspberrypi hass[4272]: DEBUG:homeassistant.components.sensor.zwave:Value changed for label Access Control
Jan 23 21:33:08 raspberrypi hass[4272]: DEBUG:homeassistant.components.sensor.zwave:Value changed for label Burglar
Jan 23 21:33:08 raspberrypi hass[4272]: DEBUG:homeassistant.components.sensor.zwave:Value changed for label Power Management
Jan 23 21:33:08 raspberrypi hass[4272]: DEBUG:homeassistant.components.sensor.zwave:Value changed for label System
Jan 23 21:33:08 raspberrypi hass[4272]: DEBUG:libopenzwave:notif_callback : end