home-assistant / core

:house_with_garden: Open source home automation that puts local control and privacy first.
https://www.home-assistant.io
Apache License 2.0
72.8k stars 30.51k forks source link

Physical switching of a zwave module does not update status in Home-Assistant #9902

Closed flyingdutchman31 closed 5 years ago

flyingdutchman31 commented 7 years ago

Make sure you are running the latest version of Home Assistant before reporting an issue.

You should only file an issue if you found a bug. Feature and enhancement requests should go in the Feature Requests section of our community forum:

Home Assistant release (hass --version): HomeAssistant 0.55.0

Python release (python3 --version): Hassio 1.1

Component/platform: Zwave Aeon Labs Z-stick S5

Description of problem: Status when a zwave module is physically triggered is not registered/updated in HomeAssistant. Zwave modules switched from within HomeAssistant does work

Expected: When I click a physical switch I would expect it to update its status in HomeAssistant

Problem-relevant configuration.yaml entries and steps to reproduce:

zwave:
  usb_path: '/dev/ttyACM0'
  debug: True
  polling_interval: 60000
  autoheal: True
  1. Its always happening. Restart of homeassistant or unplug/plugin zwave stick does not matter
  2. In the past it work instantly. Think the problem has arisen since 0.50>

Traceback (if applicable):

Additional info:

andrey-git commented 7 years ago

Which switch is it? Do you see anything in OZW log when you flip the switch?

flyingdutchman31 commented 7 years ago

Its all my switches. Duwi, Zwave.me and qubino. I dont see a registration in ozw either when I physically switch it.

When you asked I realize its probably an openzwave bug then a homeassistant one.

mbrrg commented 7 years ago

Works fine for me with 0.55 and Aeotec, Qubino and Fibaro switches/dimmers. Weird if it suddenly has stopped working for you. Some devices have configuration options where reporting back to the controller can be switched on/off, have you checked that it looks ok?

flyingdutchman31 commented 7 years ago

I will try to do a re-asociation with the controller. Or do you mean there is a homeassistant option for reporting back?

mbrrg commented 7 years ago

It's device dependent, some (most?) devices support reporting back their status, others have to be polled. Some of those that support reporting also has configuration options that can be used to switch the behavior off.

flyingdutchman31 commented 6 years ago

I had some time to play with the config again. Just did a full hardware reset of the aeon labs z-stick gen5 and only added 2 zwave devices.

When I restarted home-assistant the two devices were added but still the problem exists.

I do see this error in the ozw_log.txt:

2017-11-06 10:47:07.930 Info, Node002, Response RTT 34 Average Response RTT 81
2017-11-06 10:47:07.930 Info, Node002, Received SwitchBinary report from node 2: level=Off
2017-11-06 10:47:07.931 Detail, Node002, Refreshed Value: old value=true, new value=false, type=bool
2017-11-06 10:47:07.931 Detail, Node002, Changes to this value are not verified
2017-11-06 10:47:07.931 Detail, Node002,   Expected reply and command class was received
2017-11-06 10:47:07.931 Detail, Node002,   Message transaction complete
2017-11-06 10:47:07.931 Detail, 
2017-11-06 10:47:07.931 Detail, Node002, Removing current message
2017-11-06 10:47:07.931 Detail, Node002, Notification: ValueChanged
2017-11-06 10:47:07.942 Warning, Exception: Manager.cpp:2499 - 102 - ValueID passed to GetValueFloatPrecision is not a Decimal Value
2017-11-06 10:47:07.943 Warning, Exception: Manager.cpp:2499 - 102 - ValueID passed to GetValueFloatPrecision is not a Decimal Value

Could this be related?

flyingdutchman31 commented 6 years ago

zwcfg_0xda07e86b.txt

This i my zwcfg file. It contains 3 devices: aeon labs z-stick s5 2 x duwi ZW ES 1000 Flush Mounted Switch which always auto updated to there status to the controller in the past without any polling needed

Human commented 6 years ago

I hope my recent testing and debugging is helpful. I was trying to get polling to work, too, and the only way I see polling is by setting polling_interval super low.

My zwave yaml:

  usb_path: /dev/ttyACM1
  polling_interval: 30
  device_config_glob:
    "light.*":
      refresh_value: true
      polling_intensity: 1

From the UI updating I'm seeing and from the OZW log, the value of 30 gets me a poll result in 2-3 minutes after the physical switch is toggled. It may not be quite as simple as just reducing the interval, though, because I get a burst of 2-12 "Notification: ValueChanged" entries in the log each time I get a poll result. I can't tell if this is expected or not, but some of it seems to be it noticing the light level changing during dimming.

This shows the OZW logs after manually operating the dimmer.

This shows the OZW logs during a time when the dimmer was left alone.

I'd be happy to do more testing and to provide more logging.

Human commented 6 years ago

I wanted to add that I have the same z stick as @flyingdutchman31 but I'm on HASS 0.57.2 and python 3.4.

Human commented 6 years ago

I needed to reboot last night after hass ate all my RAM (possibly due to the insane polling value I used), but after the reboot, I switched to a polling interval of 30000, and now it somehow produces results within a few seconds. This would imply that it's some state issue, possibly a driver issue, and probably not a HASS issue.

@flyingdutchman31 do you get improved behavior after a reboot?

flyingdutchman31 commented 6 years ago

I updated homeassistant to the latest release 0.57.2 and it seema a bit better now. The 2 of the qubino modules report no there status within 2 seconds when i switch them physical.

The duwi modules still have no improvement and only report there status at a homeassistant poll or zwave node refresh.

Especially the duwi modules always were rock solid and instant in there status report

balloobbot commented 6 years ago

There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates.

Please make sure to update to the latest Home Assistant version and check if that solves the issue. Let us know if that works for you by adding a comment :+1:

yd82 commented 6 years ago

I still have the same problem. All of my zwave devices don't update status when turn on/off using physical button.

I am using latest HASS version 0.64 Nortek USB stick Zigbee and Zwave Not only my Zwave devices but also all of my Zigbee devices don't update. It's too annoying. I just changed from Smartthings hub to USB stick, using ST hub, everything update as normal.

Please help me to fix this. Thanks

ParadingLunatic commented 6 years ago

I'm also having this problem. I'm hoping to switch away from my SmartThings hub. Relatively fresh install of Hass.io (the easy rpi install). Not sure which version is what considering I see so many different version numbers. 0.101, 1.2.1, Either way it's a fresh install to an rpi 3 and fully up to date.

I have a Aeotec Gen 5 stick and two Leviton DZS15-1LZ switches. Upon initial configuration and inclusion, controlling from the dashboard is pretty instantaneous. The problem is if I switch on/off directly from the switch, the state change wasn't noticed in Hass. In my zwave config I added:

  polling_interval: 30000
  device_config_glob:
    "switch.*":
      refresh_value: true
      polling_intensity: 1

Now it does detect the change but of course it takes up to 30 seconds. Normally this wouldn't be a big deal for me but I eventually want to add another switch along with an appliance/lamp module/plug that I can set an automation to link them together so when the switch is on, it turns on the plug/lamp module. That will be REALLY annoying if it takes up to 30 seconds to trigger because it doesn't detect it for 30 seconds.

Update. Here's the log info related with turning On/Off the switch. Also it looks like it may be an openzwave issue? https://github.com/OpenZWave/open-zwave/issues/933

Update 2. At this point I don't know what to say. I removed the polling_intensity line from my configuration just to give it another shot but left the polling_interval set to 30000. Low and behold, the dashboard DOES update. Although VERY inconsistently. What I have noticed is it usually takes no more than 2 minutes to pick up on the change. Now I'm not really sure if this MIGHT have something to do with the fact that I still have SmartThings up and running with 3 Z Wave devices still hooked up to it. But I'm not exactly willing to completely switch over just to find out it doesn't help. Also the Z-Wave controller and the switches are no more than 10 feet apart from each other, but there is another switch in the same electrical box (3 switches, one box, 2 are on Hass.io, 1 is on ST).

Turning on.

2018-04-30 14:02:59.718 Detail, Node004,   Received: 0x01, 0x12, 0x00, 0x49, 0x84, 0x04, 0x0c, 0x04, 0x10, 0x03, 0x25, 0x27, 0x2b, 0x2c, 0x72, 0x86, 0x91, 0x77, 0x73, 0x5b
2018-04-30 14:02:59.718 Detail,
2018-04-30 14:02:59.718 Info, Node004, UPDATE_STATE_NODE_INFO_RECEIVED from node 4
2018-04-30 14:02:59.718 Detail, Node004, AdvanceQueries queryPending=0 queryRetries=0 queryStage=Dynamic live=1
2018-04-30 14:02:59.718 Detail, Node004, QueryStage_Dynamic
2018-04-30 14:02:59.718 Detail, Node004, Queuing (Send) SwitchBinaryCmd_Get (Node=4): 0x01, 0x09, 0x00, 0x13, 0x04, 0x02, 0x25, 0x02, 0x25, 0x5a, 0xbb
2018-04-30 14:02:59.719 Detail, Node004, Queuing (Query) Query Stage Complete (Dynamic)
2018-04-30 14:02:59.719 Detail,
2018-04-30 14:02:59.719 Info, Node004, Sending (Send) message (Callback ID=0x5a, Expected Reply=0x04) - SwitchBinaryCmd_Get (Node=4): 0x01, 0x09, 0x00, 0x13, 0x04, 0x02, 0x25, 0x02, 0x25, 0x5a, 0xbb
2018-04-30 14:02:59.727 Detail, Node004,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2018-04-30 14:02:59.727 Detail, Node004,   ZW_SEND_DATA delivered to Z-Wave stack
2018-04-30 14:02:59.745 Detail, Node004,   Received: 0x01, 0x07, 0x00, 0x13, 0x5a, 0x00, 0x00, 0x03, 0xb2
2018-04-30 14:02:59.745 Detail, Node004,   ZW_SEND_DATA Request with callback ID 0x5a received (expected 0x5a)
2018-04-30 14:02:59.745 Info, Node004, Request RTT 26 Average Request RTT 25
2018-04-30 14:02:59.745 Detail,   Expected callbackId was received
2018-04-30 14:02:59.755 Detail, Node004,   Received: 0x01, 0x0a, 0x00, 0x04, 0x00, 0x04, 0x04, 0x22, 0x01, 0x00, 0x00, 0xd2
2018-04-30 14:02:59.755 Detail,
2018-04-30 14:02:59.755 Info, Node004, Response RTT 36 Average Response RTT 35
2018-04-30 14:03:09.720 Error, Node004, ERROR: Dropping command, expected response not received after 1 attempt(s)
2018-04-30 14:03:09.720 Detail, Node004, Removing current message
2018-04-30 14:03:09.720 Detail, Node004, Notification: Notification - TimeOut
2018-04-30 14:03:09.724 Detail, Node004, Query Stage Complete (Dynamic)
2018-04-30 14:03:09.724 Detail, Node004, AdvanceQueries queryPending=0 queryRetries=0 queryStage=Configuration live=1
2018-04-30 14:03:09.724 Detail, Node004, QueryStage_Configuration
2018-04-30 14:03:09.724 Detail, Node004, QueryStage_Complete
2018-04-30 14:03:09.724 Warning, CheckCompletedNodeQueries m_allNodesQueried=1 m_awakeNodesQueried=1
2018-04-30 14:03:09.724 Detail, Node004, Notification: NodeQueriesComplete

Turning off.

2018-04-30 14:04:36.444 Detail, Node004,   Received: 0x01, 0x12, 0x00, 0x49, 0x84, 0x04, 0x0c, 0x04, 0x10, 0x03, 0x25, 0x27, 0x2b, 0x2c, 0x72, 0x86, 0x91, 0x77, 0x73, 0x5b
2018-04-30 14:04:36.444 Detail,
2018-04-30 14:04:36.444 Info, Node004, UPDATE_STATE_NODE_INFO_RECEIVED from node 4
2018-04-30 14:04:36.444 Detail, Node004, AdvanceQueries queryPending=0 queryRetries=0 queryStage=Dynamic live=1
2018-04-30 14:04:36.444 Detail, Node004, QueryStage_Dynamic
2018-04-30 14:04:36.444 Detail, Node004, Queuing (Send) SwitchBinaryCmd_Get (Node=4): 0x01, 0x09, 0x00, 0x13, 0x04, 0x02, 0x25, 0x02, 0x25, 0x5e, 0xbf
2018-04-30 14:04:36.444 Detail, Node004, Queuing (Query) Query Stage Complete (Dynamic)
2018-04-30 14:04:36.445 Detail,
2018-04-30 14:04:36.445 Info, Node004, Sending (Send) message (Callback ID=0x5e, Expected Reply=0x04) - SwitchBinaryCmd_Get (Node=4): 0x01, 0x09, 0x00, 0x13, 0x04, 0x02, 0x25, 0x02, 0x25, 0x5e, 0xbf
2018-04-30 14:04:36.453 Detail, Node004,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2018-04-30 14:04:36.453 Detail, Node004,   ZW_SEND_DATA delivered to Z-Wave stack
2018-04-30 14:04:36.470 Detail, Node004,   Received: 0x01, 0x07, 0x00, 0x13, 0x5e, 0x00, 0x00, 0x02, 0xb7
2018-04-30 14:04:36.470 Detail, Node004,   ZW_SEND_DATA Request with callback ID 0x5e received (expected 0x5e)
2018-04-30 14:04:36.470 Info, Node004, Request RTT 25 Average Request RTT 25
2018-04-30 14:04:36.470 Detail,   Expected callbackId was received
2018-04-30 14:04:36.480 Detail, Node004,   Received: 0x01, 0x0a, 0x00, 0x04, 0x00, 0x04, 0x04, 0x22, 0x01, 0x00, 0x00, 0xd2
2018-04-30 14:04:36.481 Detail,
2018-04-30 14:04:36.481 Info, Node004, Response RTT 35 Average Response RTT 35
2018-04-30 14:04:46.446 Error, Node004, ERROR: Dropping command, expected response not received after 1 attempt(s)
2018-04-30 14:04:46.446 Detail, Node004, Removing current message
2018-04-30 14:04:46.446 Detail, Node004, Notification: Notification - TimeOut
2018-04-30 14:04:46.450 Detail, Node004, Query Stage Complete (Dynamic)
2018-04-30 14:04:46.450 Detail, Node004, AdvanceQueries queryPending=0 queryRetries=0 queryStage=Configuration live=1
2018-04-30 14:04:46.450 Detail, Node004, QueryStage_Configuration
2018-04-30 14:04:46.450 Detail, Node004, QueryStage_Complete
2018-04-30 14:04:46.450 Warning, CheckCompletedNodeQueries m_allNodesQueried=1 m_awakeNodesQueried=1
2018-04-30 14:04:46.450 Detail, Node004, Notification: NodeQueriesComplete
sjakub commented 6 years ago

I use something like that for Leviton switches:

alias: 'Update Office Light'
hide_entity: true
trigger:
  - platform: state
    entity_id: zwave.office_light
condition:
  condition: or
  conditions:
    - condition: template
      value_template: '{% if states.automation.update_office_light.attributes.last_triggered == none %}True{% else %}False{% endif %}'
    - condition: template
      value_template: '{{ as_timestamp(now()) - as_timestamp(states.automation.update_office_light.attributes.last_triggered) | int > 5 }}'
action:
  - service: zwave.refresh_entity
    data:
      entity_id: switch.office_light

However, it takes 10 seconds to update the state after pushing the button. I do see "ERROR: Dropping command, expected response not received after 1 attempt(s)" messages in the log file. That message happens 10 seconds after pushing the button and that's what triggers the state change that I use in the automation above. But maybe there is a better way of doing that, within open zwave? Maybe just increasing the number of attempts would be sufficient?

aviramsegal commented 6 years ago

Same issue here. It also seems like turning on/off switches from within HA has issues updating the status as well.

edif30 commented 6 years ago

Issue for me too. No errors in the logs though. Tried re-pairing, healing, testing, refreshing, power flip flop. No dice.

ParadingLunatic commented 6 years ago

I gave up on the Leviton switches that I have (DZS15-1LZ). They're older Z-Wave and not Z-Wave plus for one. Thankfully I only had a very small handful of Z-Wave switches to start off with. I've been buying the inovelli Z-Wave plus switches from amazon which are a fraction of the price of the GE or Levitons. They've been working wonderfully for me. The only issue I have is they initially appear as inovelli unknown blah blah but the on/off and dimming features work flawlessly. There's supposed to be a way to fix that but none of the fixes have worked for me. Either way as long as they work I don't really care all that much. They also damn near instantly report back to Hassio their status. I haven't bought any of the scene enabled inovelli switches yet but they're supposed to work with some manipulating.

ghost commented 6 years ago

I have been seeing this same issue with status not updating on AEOTEC Nano series dimmers and switches, the Gen 5 ones. I am also using an AEOTEC Gen 5 Z-Stick. I can get the updating to work by mucking around in the configs for each individual device usually, but recently I had a failure and had to completely reset the z-wave network to defaults Now I can't for the life of me get the updating to work. Mine are all Z-Wave Plus devices.

OpenZWave log seems to indicate results are going through the Z-wave stack though, so not what is going on. If my issue is different and an easy fix, I'd welcome being pointed in the right direction :).

tarlen commented 6 years ago

I'm also experiencing this issue with an AEOTEC Gen 5 Z-Stick and Aeotec Micro Double switches. It worked flawlessly for over a year, then I updated Home Assistant to 0.77 and it stopped working. I've just updated to 0.79.2 (latest Hass.io offers me), and still have the issue.

I'm seeing this in OZW_Log.txt when I manually switch:

2018-10-03 09:49:40.680 Detail, 
2018-10-03 09:49:40.680 Error, Node018, Cannot find endpoint map to instance for Command Class COMMAND_CLASS_BASIC endpoint 4
2018-10-03 09:49:41.784 Detail, Node018,   Received: 0x01, 0x0d, 0x00, 0x04, 0x00, 0x12, 0x07, 0x60, 0x0d, 0x03, 0x00, 0x20, 0x03, 0x00, 0xae
2018-10-03 09:49:41.785 Detail, 
2018-10-03 09:49:41.785 Error, Node018, Cannot find endpoint map to instance for Command Class COMMAND_CLASS_BASIC endpoint 3

I changed the notification to HAIL just to make sure (I've always had it on BASIC), and I get the same thing with the different command:

2018-10-03 09:52:21.846 Detail, 
2018-10-03 09:52:21.846 Error, Node018, Cannot find endpoint map to instance for Command Class COMMAND_CLASS_HAIL endpoint 4
2018-10-03 09:52:22.950 Detail, Node018,   Received: 0x01, 0x0c, 0x00, 0x04, 0x00, 0x12, 0x06, 0x60, 0x0d, 0x03, 0x00, 0x82, 0x01, 0x0e
2018-10-03 09:52:22.951 Detail, 
2018-10-03 09:52:22.951 Error, Node018, Cannot find endpoint map to instance for Command Class COMMAND_CLASS_HAIL endpoint 3

Nothing appears in home-assistant.log.

Given the number of people I see experiencing this issue I have to assume it's a change in Home Assistant or OpenZWave.

marchingphoenix commented 5 years ago

Are you still having this issue on 0.84.x?

ghost commented 5 years ago

@marchingphoenix: My issue is mostly fixed, but I am still using 0.83 I just had to go to basic reporting and save the setting half a dozen times before it took. It is not perfect, still sometimes a couple of seconds delay and sometimes the light will turn on and off and back on again. I'll try updating over the weekend once I check the breaking changes. It's only affecting a couple of devices for me as mostly I use MQTT and Arduino devices for the lights. The Zwave switches are just in a couple of places where cabling was difficult to access 🙂

tarlen commented 5 years ago

Are you still having this issue on 0.84.x?

@marchingphoenix I've just updated from 0.82.1 to 0.84.2 and it seems to be working as expected. Thanks!

marchingphoenix commented 5 years ago

Great to hear, I'll go ahead and close this out.

sgruby commented 5 years ago

I just started with Z-Wave on Home Assistant (0.84.6) on HassOS 1.13 (Hass.io 141) with an AEOTEC Gen 5 Z-Stick and am experiencing this problem with numerous Leviton VRS15-1LZ switches. HA gets the Hail command, sends the request to get status, ZWave appears to make 1 attempt and gives up.

2018-12-31 17:17:57.186 Detail, 2018-12-31 17:17:57.186 Info, Node004, Response RTT 93 Average Response RTT 122 2018-12-31 17:17:58.070 Detail, Node004, Received: 0x01, 0x08, 0x00, 0x04, 0x00, 0x04, 0x02, 0x82, 0x01, 0x76 2018-12-31 17:17:58.071 Detail, 2018-12-31 17:17:58.071 Info, Node004, Response RTT 978 Average Response RTT 550 2018-12-31 17:17:58.071 Info, Node004, Received Hail command from node 4 2018-12-31 17:17:58.071 Detail, Node004, Queuing (Send) SwitchBinaryCmd_Get (Node=4): 0x01, 0x09, 0x00, 0x13, 0x04, 0x02, 0x25, 0x02, 0x25, 0xef, 0x0e 2018-12-31 17:18:07.093 Error, Node004, ERROR: Dropping command, expected response not received after 1 attempt(s) 2018-12-31 17:18:07.093 Detail, Node004, Removing current message 2018-12-31 17:18:07.094 Detail, Node004, Notification: Notification - TimeOut 2018-12-31 17:18:07.112 Detail, 2018-12-31 17:18:07.112 Info, Node004, Sending (Send) message (Callback ID=0xef, Expected Reply=0x04) - SwitchBinaryCmd_Get (Node=4): 0x01, 0x09, 0x00, 0x13, 0x04, 0x02, 0x25, 0x02, 0x25, 0xef, 0x0e 2018-12-31 17:18:07.120 Detail, Node004, Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8

It looks like maybe OpenZWave should pause after it receives the HAIL command or at least attempt the get a second time. Maybe the switch can't handle send and receive at the same time. This switch is over 5 years old, but works well in Vera.

Any suggestions? This thread doesn't really indicate what fix was made to have the problem go away.

Thanks!

ghost commented 5 years ago

I have no suggestions on a fix, maybe try using Basic CC to get the switch status instead of Hail CC? I had a bit of a muck around getting reporting right for my Aeotec switches also.

Other than that, this looks like an OZW issue. Maybe raise an issue on their issue logger also. There are some pretty knowledgeable people there too. :)

sgruby commented 5 years ago

Thanks for the reply on this old thread! When you say use Basic command class to get the switch status, how do I go about doing that? Do I have to set a configuration on the switch or do I watch for an event and get the status myself?

There is a thread on the OpenZWave side for this that was closed as well. https://github.com/OpenZWave/open-zwave/issues/933 . I'll add to that as well.

Thanks.

ghost commented 5 years ago

It is done in the Zwave control panel. For that, we would be better taking this away from here and to it's own topic I think as it is out of scope for this thread