search

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
73.18k stars 30.57k forks source link

Vera Scene Controllers Show Unknown After 106 Upgrade #32231

Closed monsieurlatte closed 4 years ago

monsieurlatte commented 4 years ago

Vera Scene Controllers Show Unknown After 106 Upgrade

Environment

monsieurlatte commented 4 years ago

Bump, anything on this? Still not working, I have even tried removing the scene controllers and adding them back in, they are WAZ0001 models from gocontrol. https://www.gocontrol.com/detail.php?productId=12

addisonlynch commented 4 years ago

+1. Having the same issue

addisonlynch commented 4 years ago

@vangorra are you aware of any outstanding issues with vera scene controllers?

vangorra commented 4 years ago

This is the third report for entities showing unavailable. Still haven't been able to reproduce with either of my controllers. Still trying.

vangorra commented 4 years ago

@addisonlynch, @monsieurlatte Do lights, switches or any other devices that are managed by vera still work when the scene is unavailable? Are those unavailable too? Is there anything in the logs that mention vera?

This seems to have been an intermittent issue for a long time now. I'd like to fix it but have no been able to get any data.

vangorra commented 4 years ago

Looks like this also has a similar symptom. There was no code changes to the vera component between the versions @monsieurlatte reports.

$ git checkout 0.105.5
Previous HEAD position was 76d2658101 Merge pull request #31550 from home-assistant/rc
HEAD is now at 75b508e872 Merge pull request #31931 from home-assistant/rc
$ git diff 0.106.0 homeassistant/components/vera/
$
vangorra commented 4 years ago

@addisonlynch, @monsieurlatte, @geekofweek, @reesion, @mcaminiti Will you collect some more detailed logs? Here's the setting for configuration.yaml

logger:
  default: info
  logs:
    pyvera: 'debug'
    homeassistant.components.vera: 'debug'

I'm looking for what happens between polls of the vera controller. Polling occurs every second. So if you could grab a chunk of the log between DEBUG (Vera Poll Thread) [pyvera.subscribe] Polling for Vera changes, change some states directly on the controllers (open doors, switch lights, etc). That should result in a big dump of data when the next poll runs. In this case, no data also tells us something too.

Here's an example of my output for several poll checks.

2020-05-05 06:54:06 DEBUG (Vera Poll Thread) [pyvera.subscribe] Polling for Vera changes
2020-05-05 06:54:06 DEBUG (Vera Poll Thread) [pyvera] get_changed_devices() requesting payload {'timeout': 30, 'minimumdelay': 200, 'id': 'lu_sdata', 'loadtime': 1588652753, 'dataversion': 652758201}
2020-05-05 06:54:16 DEBUG (Vera Poll Thread) [pyvera] get_alerts() requesting payload {'LoadTime': 1588652753, 'DataVersion': 652758201, 'id': 'status'}
2020-05-05 06:54:16 DEBUG (Vera Poll Thread) [pyvera.subscribe] Poll returned
2020-05-05 06:54:16 DEBUG (Vera Poll Thread) [pyvera.subscribe] Event: Greenhouse fan, state -1, alerts 0, {"altid": "28", "id": "81", "subcategory": "1", "room": "1", "parent": "1", "status": "0", "kwh": "114.6510", "configured": "1", "commFailure": "0", "watts": "0", "state": "-1", "comment": ""}
2020-05-05 06:54:17 DEBUG (Vera Poll Thread) [pyvera.subscribe] Polling for Vera changes
2020-05-05 06:54:17 DEBUG (Vera Poll Thread) [pyvera] get_changed_devices() requesting payload {'timeout': 30, 'minimumdelay': 200, 'id': 'lu_sdata', 'loadtime': 1588652753, 'dataversion': 652758202}
2020-05-05 06:54:18 DEBUG (Vera Poll Thread) [pyvera] get_alerts() requesting payload {'LoadTime': 1588652753, 'DataVersion': 652758202, 'id': 'status'}
2020-05-05 06:54:18 DEBUG (Vera Poll Thread) [pyvera.subscribe] Poll returned
2020-05-05 06:54:18 DEBUG (Vera Poll Thread) [pyvera.subscribe] Event: Greenhouse fan, state -1, alerts 0, {"altid": "28", "id": "81", "subcategory": "1", "room": "1", "parent": "1", "status": "0", "kwh": "114.6510", "configured": "1", "commFailure": "0", "state": "-1", "comment": "", "watts": "-1"}
2020-05-05 06:54:19 DEBUG (Vera Poll Thread) [pyvera.subscribe] Polling for Vera changes
2020-05-05 06:54:19 DEBUG (Vera Poll Thread) [pyvera] get_changed_devices() requesting payload {'timeout': 30, 'minimumdelay': 200, 'id': 'lu_sdata', 'loadtime': 1588652753, 'dataversion': 652758204}
2020-05-05 06:54:44 DEBUG (Vera Poll Thread) [pyvera] get_alerts() requesting payload {'LoadTime': 1588652753, 'DataVersion': 652758204, 'id': 'status'}
2020-05-05 06:54:44 DEBUG (Vera Poll Thread) [pyvera.subscribe] Poll returned

This issue smells like a race condition, I have a suspicion about the cause but need more data to attempt to reproduce and repair.

vangorra commented 4 years ago

Also, I'm looking for exceptions/output during startup like:

2020-05-05 07:08:42 ERROR (MainThread) [homeassistant.config_entries] Error setting up entry http://10.40.8.245:3480 for vera
Traceback (most recent call last):
  File "/home/rvangork/Documents/git/home-assistant/homeassistant/config_entries.py", line 215, in async_setup
    result = await component.async_setup_entry(  # type: ignore
  File "/home/rvangork/Documents/git/home-assistant/homeassistant/components/vera/__init__.py", line 100, in async_setup_entry

OR

2020-05-05 07:09:27 ERROR (MainThread) [homeassistant.components.vera] Error communicating with Vera API
Traceback (most recent call last):
  File "/home/rvangork/Documents/git/home-assistant/homeassistant/components/vera/__init__.py", line 100, in async_setup_entry

OR

2020-05-05 07:10:32 INFO (MainThread) [homeassistant.components.switch] Setting up switch.vera
2020-05-05 07:10:32 INFO (MainThread) [homeassistant.components.binary_sensor] Setting up binary_sensor.vera
2020-05-05 07:10:32 INFO (MainThread) [homeassistant.setup] Setup of domain light took 0.0 seconds.
2020-05-05 07:10:32 INFO (MainThread) [homeassistant.components.climate] Setting up climate.vera
2020-05-05 07:10:32 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.vera
2020-05-05 07:10:32 INFO (MainThread) [homeassistant.setup] Setup of domain scene took 0.0 seconds.
2020-05-05 07:10:32 INFO (MainThread) [homeassistant.components.light] Setting up light.vera
2020-05-05 07:10:32 INFO (MainThread) [homeassistant.components.scene] Setting up scene.vera
geekofweek commented 4 years ago

No issues that I can discern on startup, all of the domains setup properly:

2020-05-05 09:18:57 INFO (MainThread) [homeassistant.components.lock] Setting up lock.vera
2020-05-05 09:18:57 INFO (MainThread) [homeassistant.setup] Setup of domain lock took 0.0 seconds.

2020-05-05 09:19:02 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.vera
2020-05-05 09:19:02 INFO (MainThread) [homeassistant.setup] Setup of domain sensor took 5.1 seconds.

2020-05-05 09:18:57 INFO (MainThread) [homeassistant.:/climate.omponents.switch] Setting up switch.vera

2020-05-05 09:19:23 INFO (MainThread) [homeassistant.setup] Setup of domain binary_sensor took 26.6 seconds.
2020-05-05 09:19:23 INFO (MainThread) [homeassistant.components.binary_sensor] Setting up binary_sensor.vera

Only thing I find in relation to the light sensors is when it starts to fire. I tried to narrow it down to one of those sensors in particular. I don't seem to get any polling on the device until it reports the first state change. I can usually force it by changing the lights in the room by a large margin to force an update.

2020-05-05 09:08:36 DEBUG (Vera Poll Thread) [pyvera.subscribe] Event: Office, state 999, alerts 0, {"altid": "m3", "id": "36", "subcategory": "0", "room": "9", "parent": "35", "configured": "0", "light": "17"}
2020-05-05 09:08:37 DEBUG (Vera Poll Thread) [pyvera.subscribe] Polling for Vera changes
2020-05-05 09:08:37 DEBUG (Vera Poll Thread) [pyvera] get_changed_devices() requesting payload {'timeout': 30, 'minimumdelay': 200, 'id': 'lu_sdata', 'loadtime': 1588573377, 'dataversion': 573398477}
2020-05-05 09:08:55 DEBUG (Vera Poll Thread) [pyvera] get_alerts() requesting payload {'LoadTime': 1588573377, 'DataVersion': 573398477, 'id': 'status'}
2020-05-05 09:08:55 DEBUG (Vera Poll Thread) [pyvera.subscribe] Poll returned
vangorra commented 4 years ago

@geekofweek So does one of the unavailable entities have a log entry with Vera Poll Thread when it is changed from the vera controller? Opening a door or slipping a switch is the most reliable. Motion sensors tend to cache results for a period of time and are not a reliable debug tool.

mcaminiti commented 4 years ago

I'm attaching some debug logs and filtered to just vera. My issue is around the "Temperature Sensor" from my Basement Motion Sensor (secondary sensor from Vera). Its renamed to Basement Temperature Sensor but the name in debug seems to be original name of entity.

Startup seems fine.

2020-05-05 09:25:36 INFO (MainThread) [homeassistant.setup] Setup of domain vera took 0.0 seconds.

2020-05-05 09:25:37 DEBUG (Vera Poll Thread) [pyvera.subscribe] Polling for Vera changes
2020-05-05 09:25:37 DEBUG (Vera Poll Thread) [pyvera] get_changed_devices() requesting payload {'timeout': 30, 'minimumdelay': 200, 'id': 'lu_sdata', 'dataversion': 1, 'loadtime': 0}
2020-05-05 09:25:37 DEBUG (Vera Poll Thread) [pyvera] get_alerts() requesting payload {'LoadTime': 0, 'DataVersion': 1, 'id': 'status'}
2020-05-05 09:25:37 INFO (SyncWorker_6) [nest.nest] Event loop started.
2020-05-05 09:25:37 DEBUG (Vera Poll Thread) [pyvera.subscribe] Poll returned

Sensor Startup

2020-05-05 09:25:45 INFO (MainThread) [homeassistant.setup] Setup of domain sensor took 6.1 seconds.
2020-05-05 09:25:45 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.nut
2020-05-05 09:25:45 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.roomba
2020-05-05 09:25:45 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.nest
2020-05-05 09:25:45 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.vera
2020-05-05 09:25:45 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.ecobee
2020-05-05 09:25:45 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.plex
2020-05-05 09:25:45 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.esphome
2020-05-05 09:25:45 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.esphome
2020-05-05 09:25:45 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.esphome
2020-05-05 09:25:45 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.ring
2020-05-05 09:25:45 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.hue
2020-05-05 09:25:45 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.ios
2020-05-05 09:25:45 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.unifi
2020-05-05 09:25:45 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.ipp
2020-05-05 09:25:45 DEBUG (MainThread) [pyvera.subscribe] Subscribing to events for Temperature Sensor
2020-05-05 09:25:45 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.lutron_caseta_pro
2020-05-05 09:25:45 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.envisalink

Example polling of the motion sensor (other sensors change too all the time, but I will leave it running in debug until the temperature changes on the "Unavailable" sensor. 

2020-05-05 09:34:06 DEBUG (Vera Poll Thread) [pyvera.subscribe] Polling for Vera changes
2020-05-05 09:34:06 DEBUG (Vera Poll Thread) [pyvera] get_changed_devices() requesting payload {'timeout': 30, 'minimumdelay': 200, 'id': 'lu_sdata', 'loadtime': 1588647021, 'dataversion': 647055601}
2020-05-05 09:34:06 DEBUG (Vera Poll Thread) [pyvera] get_alerts() requesting payload {'LoadTime': 1588647021, 'DataVersion': 647055601, 'id': 'status'}
2020-05-05 09:34:06 DEBUG (Vera Poll Thread) [pyvera.subscribe] Poll returned
2020-05-05 09:34:07 DEBUG (Vera Poll Thread) [pyvera.subscribe] Polling for Vera changes
2020-05-05 09:34:07 DEBUG (Vera Poll Thread) [pyvera] get_changed_devices() requesting payload {'timeout': 30, 'minimumdelay': 200, 'id': 'lu_sdata', 'loadtime': 1588647021, 'dataversion': 647055604}
2020-05-05 09:34:11 INFO (SyncWorker_9) [root] Sending handshake.
2020-05-05 09:34:11 DEBUG (Vera Poll Thread) [pyvera] get_alerts() requesting payload {'LoadTime': 1588647021, 'DataVersion': 647055604, 'id': 'status'}
2020-05-05 09:34:11 DEBUG (Vera Poll Thread) [pyvera.subscribe] Poll returned
2020-05-05 09:34:11 DEBUG (Vera Poll Thread) [pyvera.subscribe] Event: Basement Motion Sensor, state -1, alerts 0, {"altid": "11", "id": "28", "subcategory": "3", "room": "0", "parent": "1", "armed": "0", "armedtripped": "0", "configured": "1", "batterylevel": "100", "state": "-1", "comment": "", "lasttrip": "1588689252", "tripped": "1"}
2020-05-05 09:34:11 DEBUG (Vera Poll Thread) [pyvera.subscribe] Event: Basement Motion Sensor, state -1, alerts 0, {"altid": "11", "id": "28", "subcategory": "3", "room": "0", "parent": "1", "armed": "0", "armedtripped": "0", "configured": "1", "batterylevel": "100", "state": "-1", "comment": "", "lasttrip": "1588689252", "tripped": "1"}
2020-05-05 09:34:12 DEBUG (Vera Poll Thread) [pyvera.subscribe] Polling for Vera changes
2020-05-05 09:34:12 DEBUG (Vera Poll Thread) [pyvera] get_changed_devices() requesting payload {'timeout': 30, 'minimumdelay': 200, 'id': 'lu_sdata', 'loadtime': 1588647021, 'dataversion': 647055606}
2020-05-05 09:34:21 DEBUG (Vera Poll Thread) [pyvera] get_alerts() requesting payload {'LoadTime': 1588647021, 'DataVersion': 647055606, 'id': 'status'}
2020-05-05 09:34:21 DEBUG (Vera Poll Thread) [pyvera.subscribe] Poll returned
2020-05-05 09:34:21 DEBUG (Vera Poll Thread) [pyvera.subscribe] Event: Biocube CH1 Pump, state 999, alerts 0, {"altid": "e1", "id": "66", "subcategory": "0", "room": "0", "parent": "65", "status": "1", "configured": "0", "kwh": "29.6800", "watts": "15.3"}
2020-05-05 09:34:22 INFO (SyncWorker_2) [root] Sending handshake.
2020-05-05 09:34:22 DEBUG (Vera Poll Thread) [pyvera.subscribe] Polling for Vera changes
2020-05-05 09:34:22 DEBUG (Vera Poll Thread) [pyvera] get_changed_devices() requesting payload {'timeout': 30, 'minimumdelay': 200, 'id': 'lu_sdata', 'loadtime': 1588647021, 'dataversion': 647055607}
2020-05-05 09:34:22 DEBUG (Vera Poll Thread) [pyvera] get_alerts() requesting payload {'LoadTime': 1588647021, 'DataVersion': 647055607, 'id': 'status'}
2020-05-05 09:34:22 DEBUG (Vera Poll Thread) [pyvera.subscribe] Poll returned
2020-05-05 09:34:23 DEBUG (Vera Poll Thread) [pyvera.subscribe] Polling for Vera changes
2020-05-05 09:34:23 DEBUG (Vera Poll Thread) [pyvera] get_changed_devices() requesting payload {'timeout': 30, 'minimumdelay': 200, 'id': 'lu_sdata', 'loadtime': 1588647021, 'dataversion': 647055612}
2020-05-05 09:34:27 DEBUG (Vera Poll Thread) [pyvera] get_alerts() requesting payload {'LoadTime': 1588647021, 'DataVersion': 647055612, 'id': 'status'}

I thought triggering the motion sensor would trigger the temperature update too but still waiting on a temperature update for the missing entity.

Full log still kept if needed. If the temp sensor updates and reports in, I will try and find the log around that period.

geekofweek commented 4 years ago

@vangorra let me double check, but the only sensors showing unknown are the light level sensors, which in turn are combo motion / light level devices. Everything seems fine, but those are the only ones with numeric values.

mcaminiti commented 4 years ago

Mine finally showed up this afternoon and now the numeric value is displayed in HA. Here is the debug log details from that time showing a large payload of updates.


20-05-05 13:55:06 DEBUG (Vera Poll Thread) [pyvera.subscribe] Polling for Vera changes
2020-05-05 13:55:06 DEBUG (Vera Poll Thread) [pyvera] get_changed_devices() requesting payload {'timeout': 30, 'minimumdelay': 200, 'id': 'lu_sdata', 'loadtime': 1588647021, 'dataversion': 647065410}
2020-05-05 13:55:06 DEBUG (Vera Poll Thread) [pyvera] get_alerts() requesting payload {'LoadTime': 1588647021, 'DataVersion': 647065410, 'id': 'status'}
2020-05-05 13:55:06 DEBUG (Vera Poll Thread) [pyvera.subscribe] Poll returned
2020-05-05 13:55:07 DEBUG (Vera Poll Thread) [pyvera.subscribe] Polling for Vera changes
2020-05-05 13:55:07 DEBUG (Vera Poll Thread) [pyvera] get_changed_devices() requesting payload {'timeout': 30, 'minimumdelay': 200, 'id': 'lu_sdata', 'loadtime': 1588647021, 'dataversion': 647065413}
2020-05-05 13:55:12 DEBUG (Vera Poll Thread) [pyvera.subscribe] Poll returned
2020-05-05 13:55:12 DEBUG (Vera Poll Thread) [pyvera.subscribe] No changes in poll interval
2020-05-05 13:55:13 DEBUG (Vera Poll Thread) [pyvera.subscribe] Polling for Vera changes
2020-05-05 13:55:13 DEBUG (Vera Poll Thread) [pyvera] get_changed_devices() requesting payload {'timeout': 30, 'minimumdelay': 200, 'id': 'lu_sdata', 'loadtime': 1588704914, 'dataversion': 647065413}
2020-05-05 13:55:17 INFO (SyncWorker_7) [root] Sending handshake.
2020-05-05 13:55:17 DEBUG (Vera Poll Thread) [pyvera.subscribe] Caught RequestException: ('Connection aborted.', RemoteDisconnected('Remote end closed connection without response'))
2020-05-05 13:55:17 INFO (Vera Poll Thread) [pyvera.subscribe] Could not poll Vera - will retry in 9s
2020-05-05 13:55:27 DEBUG (Vera Poll Thread) [pyvera.subscribe] Polling for Vera changes
2020-05-05 13:55:27 DEBUG (Vera Poll Thread) [pyvera] get_changed_devices() requesting payload {'timeout': 30, 'minimumdelay': 200, 'id': 'lu_sdata', 'dataversion': 1, 'loadtime': 0}
2020-05-05 13:55:27 DEBUG (Vera Poll Thread) [pyvera] get_alerts() requesting payload {'LoadTime': 0, 'DataVersion': 1, 'id': 'status'}
2020-05-05 13:55:27 DEBUG (Vera Poll Thread) [pyvera.subscribe] Poll returned
2020-05-05 13:55:27 DEBUG (Vera Poll Thread) [pyvera.subscribe] Event: Outside Lights, state 999, alerts 0, {"name": "Outside Lights", "altid": "5", "id": 22, "category": 3, "subcategory": 0, "room": 0, "parent": 1, "status": "1", "configured": "1"}
2020-05-05 13:55:27 DEBUG (Vera Poll Thread) [pyvera.subscribe] Event: Pantry Door, state 999, alerts 0, {"name": "Pantry Door", "altid": "6", "id": 23, "category": 4, "subcategory": 1, "room": 0, "parent": 1, "armed": "0", "lasttrip": "1588703831", "tripped": "0", "armedtripped": "0", "configured": "1", "batterylevel": "100"}
2020-05-05 13:55:27 DEBUG (Vera Poll Thread) [pyvera.subscribe] Event: Pantry Door, state 999, alerts 0, {"name": "Pantry Door", "altid": "6", "id": 23, "category": 4, "subcategory": 1, "room": 0, "parent": 1, "armed": "0", "lasttrip": "1588703831", "tripped": "0", "armedtripped": "0", "configured": "1", "batterylevel": "100"}
2020-05-05 13:55:27 DEBUG (Vera Poll Thread) [pyvera.subscribe] Event: Hall Closet Door, state 999, alerts 0, {"name": "Hall Closet Door", "altid": "7", "id": 24, "category": 4, "subcategory": 1, "room": 0, "parent": 1, "armed": "0", "lasttrip": "1588693902", "tripped": "0", "armedtripped": "0", "configured": "1", "batterylevel": "100"}
2020-05-05 13:55:27 DEBUG (Vera Poll Thread) [pyvera.subscribe] Event: Hall Closet Door, state 999, alerts 0, {"name": "Hall Closet Door", "altid": "7", "id": 24, "category": 4, "subcategory": 1, "room": 0, "parent": 1, "armed": "0", "lasttrip": "1588693902", "tripped": "0", "armedtripped": "0", "configured": "1", "batterylevel": "100"}
2020-05-05 13:55:27 DEBUG (Vera Poll Thread) [pyvera.subscribe] Event: Kitchen Sink Water Sensor, state 999, alerts 0, {"name": "Kitchen Sink Water Sensor", "altid": "8", "id": 25, "category": 4, "subcategory": 2, "room": 0, "parent": 1, "armed": "1", "armedtripped": "0", "configured": "1", "batterylevel": "100"}
2020-05-05 13:55:27 DEBUG (Vera Poll Thread) [pyvera.subscribe] Event: Kitchen Sink Water Sensor, state 999, alerts 0, {"name": "Kitchen Sink Water Sensor", "altid": "8", "id": 25, "category": 4, "subcategory": 2, "room": 0, "parent": 1, "armed": "1", "armedtripped": "0", "configured": "1", "batterylevel": "100"}
2020-05-05 13:55:27 DEBUG (Vera Poll Thread) [pyvera.subscribe] Event: Refrigerator Water Sensor, state 999, alerts 10, {"name": "Refrigerator Water Sensor", "altid": "9", "id": 26, "category": 4, "subcategory": 2, "room": 0, "parent": 1, "armed": "1", "armedtripped": "0", "lasttrip": "1588647924", "tripped": "0", "configured": "1", "batterylevel": "100"}
2020-05-05 13:55:27 DEBUG (Vera Poll Thread) [pyvera.subscribe] Event: Refrigerator Water Sensor, state 999, alerts 10, {"name": "Refrigerator Water Sensor", "altid": "9", "id": 26, "category": 4, "subcategory": 2, "room": 0, "parent": 1, "armed": "1", "armedtripped": "0", "lasttrip": "1588647924", "tripped": "0", "configured": "1", "batterylevel": "100"}
2020-05-05 13:55:27 DEBUG (Vera Poll Thread) [pyvera.subscribe] Event: Washing Machine Water Sensor, state 999, alerts 0, {"name": "Washing Machine Water Sensor", "altid": "10", "id": 27, "category": 4, "subcategory": 2, "room": 0, "parent": 1, "armed": "1", "armedtripped": "0", "configured": "1", "batterylevel": "90"}
2020-05-05 13:55:27 DEBUG (Vera Poll Thread) [pyvera.subscribe] Event: Washing Machine Water Sensor, state 999, alerts 0, {"name": "Washing Machine Water Sensor", "altid": "10", "id": 27, "category": 4, "subcategory": 2, "room": 0, "parent": 1, "armed": "1", "armedtripped": "0", "configured": "1", "batterylevel": "90"}
2020-05-05 13:55:27 DEBUG (Vera Poll Thread) [pyvera.subscribe] Event: Basement Motion Sensor, state 999, alerts 0, {"name": "Basement Motion Sensor", "altid": "11", "id": 28, "category": 4, "subcategory": 3, "room": 0, "parent": 1, "armed": "0", "lasttrip": "1588701706", "tripped": "0", "armedtripped": "0", "configured": "1", "batterylevel": "100"}
2020-05-05 13:55:27 DEBUG (Vera Poll Thread) [pyvera.subscribe] Event: Basement Motion Sensor, state 999, alerts 0, {"name": "Basement Motion Sensor", "altid": "11", "id": 28, "category": 4, "subcategory": 3, "room": 0, "parent": 1, "armed": "0", "lasttrip": "1588701706", "tripped": "0", "armedtripped": "0", "configured": "1", "batterylevel": "100"}

2020-05-05 13:55:27 DEBUG (Vera Poll Thread) [pyvera.subscribe] Event: Temperature Sensor, state 999, alerts 0, {"name": "Basement Temperature Sensor", "altid": "m1", "id": 29, "category": 17, "subcategory": 0, "room": 0, "parent": 28, "temperature": "68.00", "configured": "0"}

^^^^^^ Problem Device ^^^^^^

2020-05-05 13:55:27 DEBUG (Vera Poll Thread) [pyvera.subscribe] Event: Basement Door, state 999, alerts 0, {"name": "Basement Door", "altid": "13", "id": 31, "category": 4, "subcategory": 1, "room": 0, "parent": 1, "armed": "0", "lasttrip": "1588636245", "tripped": "0", "armedtripped": "0", "configured": "1", "batterylevel": "100"}
2020-05-05 13:55:27 DEBUG (Vera Poll Thread) [pyvera.subscribe] Event: Basement Door, state 999, alerts 0, {"name": "Basement Door", "altid": "13", "id": 31, "category": 4, "subcategory": 1, "room": 0, "parent": 1, "armed": "0", "lasttrip": "1588636245", "tripped": "0", "armedtripped": "0", "configured": "1", "batterylevel": "100"}
2020-05-05 13:55:27 DEBUG (Vera Poll Thread) [pyvera.subscribe] Event: Filtration Water Sensor, state 999, alerts 0, {"name": "Filtration Water Sensor", "altid": "14", "id": 32, "category": 4, "subcategory": 2, "room": 0, "parent": 1, "armed": "1", "armedtripped": "0", "lasttrip": "1588645580", "tripped": "0", "configured": "1", "batterylevel": "100"}
2020-05-05 13:55:27 DEBUG (Vera Poll Thread) [pyvera.subscribe] Event: Filtration Water Sensor, state 999, alerts 0, {"name": "Filtration Water Sensor", "altid": "14", "id": 32, "category": 4, "subcategory": 2, "room": 0, "parent": 1, "armed": "1", "armedtripped": "0", "lasttrip": "1588645580", "tripped": "0", "configured": "1", "batterylevel": "100"}
2020-05-05 13:55:27 DEBUG (Vera Poll Thread) [pyvera.subscribe] Event: Basement Drain Water Sensor, state 999, alerts 0, {"name": "Basement Drain Water Sensor", "altid": "15", "id": 33, "category": 4, "subcategory": 2, "room": 0, "parent": 1, "armed": "1", "armedtripped": "0", "configured": "1", "batterylevel": "82"}
2020-05-05 13:55:27 DEBUG (Vera Poll Thread) [pyvera.subscribe] Event: Basement Drain Water Sensor, state 999, alerts 0, {"name": "Basement Drain Water Sensor", "altid": "15", "id": 33, "category": 4, "subcategory": 2, "room": 0, "parent": 1, "armed": "1", "armedtripped": "0", "configured": "1", "batterylevel": "82"}
2020-05-05 13:55:27 DEBUG (Vera Poll Thread) [pyvera.subscribe] Event: USER4 Ceiling Light, state 999, alerts 0, {"name": "USER4 Ceiling Light", "altid": "17", "id": 43, "category": 2, "subcategory": 0, "room": 0, "parent": 1, "status": "0", "level": "0", "configured": "1"}
2020-05-05 13:55:27 DEBUG (Vera Poll Thread) [pyvera.subscribe] Event: USER3 Ceiling Light, state 999, alerts 0, {"name": "USER3 Ceiling Light", "altid": "18", "id": 44, "category": 2, "subcategory": 0, "room": 0, "parent": 1, "status": "1", "level": "100", "configured": "1"}
2020-05-05 13:55:27 DEBUG (Vera Poll Thread) [pyvera.subscribe] Event: Fireplace, state 999, alerts 0, {"name": "Fireplace", "altid": "20", "id": 53, "category": 3, "subcategory": 1, "room": 0, "parent": 1, "status": "1", "kwh": "2.9260", "watts": "0.840", "configured": "1"}
2020-05-05 13:55:27 DEBUG (Vera Poll Thread) [pyvera.subscribe] Event: Biocube ALL, state 999, alerts 0, {"name": "Biocube ALL", "altid": "22", "id": 65, "category": 3, "subcategory": 0, "room": 0, "parent": 1, "status": "1", "kwh": "73.4600", "configured": "1", "commFailure": "0", "watts": "45.8"}
2020-05-05 13:55:27 DEBUG (Vera Poll Thread) [pyvera.subscribe] Event: Biocube CH1 Pump, state 999, alerts 0, {"name": "Biocube CH1 Pump", "altid": "e1", "id": 66, "category": 3, "subcategory": 0, "room": 0, "parent": 65, "status": "1", "watts": "15.4", "kwh": "29.7500", "configured": "0"}
2020-05-05 13:55:27 DEBUG (Vera Poll Thread) [pyvera.subscribe] Event: Biocube CH2 Heater, state 999, alerts 0, {"name": "Biocube CH2 Heater", "altid": "e2", "id": 67, "category": 3, "subcategory": 0, "room": 0, "parent": 65, "status": "1", "watts": "0.0", "kwh": "20.1900", "configured": "0"}
2020-05-05 13:55:27 DEBUG (Vera Poll Thread) [pyvera.subscribe] Event: Biocube CH3 ATO, state 999, alerts 0, {"name": "Biocube CH3 ATO", "altid": "e3", "id": 68, "category": 3, "subcategory": 0, "room": 0, "parent": 65, "status": "1", "watts": "0.0", "kwh": "0.3500", "configured": "0"}
2020-05-05 13:55:27 DEBUG (Vera Poll Thread) [pyvera.subscribe] Event: Biocube CH4 Wavemaker, state 999, alerts 0, {"name": "Biocube CH4 Wavemaker", "altid": "e4", "id": 69, "category": 3, "subcategory": 0, "room": 0, "parent": 65, "status": "1", "watts": "3.2", "kwh": "0.8000", "configured": "0"}
2020-05-05 13:55:27 DEBUG (Vera Poll Thread) [pyvera.subscribe] Event: Biocube CH5 Lights, state 999, alerts 0, {"name": "Biocube CH5 Lights", "altid": "e5", "id": 70, "category": 3, "subcategory": 0, "room": 0, "parent": 65, "status": "1", "watts": "27.2", "kwh": "22.3700", "configured": "0"}
2020-05-05 13:55:27 DEBUG (Vera Poll Thread) [pyvera.subscribe] Event: Biocube USB1, state 999, alerts 0, {"name": "Biocube USB1", "altid": "e6", "id": 71, "category": 3, "subcategory": 0, "room": 0, "parent": 65, "status": "1", "configured": "0"}
2020-05-05 13:55:27 DEBUG (Vera Poll Thread) [pyvera.subscribe] Event: Biocube USB2, state 999, alerts 0, {"name": "Biocube USB2", "altid": "e7", "id": 72, "category": 3, "subcategory": 0, "room": 0, "parent": 65, "status": "1", "configured": "0"}
2020-05-05 13:55:28 INFO (SyncWorker_19) [root] Sending handshake.
2020-05-05 13:55:28 DEBUG (Vera Poll Thread) [pyvera.subscribe] Polling for Vera changes
2020-05-05 13:55:28 DEBUG (Vera Poll Thread) [pyvera] get_changed_devices() requesting payload {'timeout': 30, 'minimumdelay': 200, 'id': 'lu_sdata', 'loadtime': 1588704918, 'dataversion': 704918058}
2020-05-05 13:55:28 DEBUG (Vera Poll Thread) [pyvera] get_alerts() requesting payload {'LoadTime': 1588704918, 'DataVersion': 704918058, 'id': 'status'}
2020-05-05 13:55:28 DEBUG (Vera Poll Thread) [pyvera.subscribe] Poll returned
2020-05-05 13:55:29 DEBUG (Vera Poll Thread) [pyvera.subscribe] Polling for Vera changes
2020-05-05 13:55:29 DEBUG (Vera Poll Thread) [pyvera] get_changed_devices() requesting payload {'timeout': 30, 'minimumdelay': 200, 'id': 'lu_sdata', 'loadtime': 1588704918, 'dataversion': 704918076}```

I renamed the device in Vera as it was Temperature Sensor and renamed to Basement Temperature Sensor. Maybe this forced the mass update and corrected the issue as well.
vangorra commented 4 years ago

The vera component makes use of a controller endpoint that long polls for status changes. It's suppose to return only what changes between calls. After seeing the logs and @digitalMedic's comments in https://github.com/home-assistant/core/issues/35140#issuecomment-624364308, I'm not confident this feature of the controller works reliably. I've updated the pyvera code to allow overriding of the data collection. Once that library gets a new release, I'll add code to see if we can get your controllers responding reliably.

mcaminiti commented 4 years ago

As another round of oddness with this vera problem, I am now having issues with my Zooz Zwave switches that are coming up in the wrong state on restart. Its causing me a lot of issues as I have a Zooz Powerstrip running my fishtank devices and automations are triggering thinking its off and not running. Vera shows the correct power usage, status. See screenshots. Not sure if connected or another issue since my previous issue was merged to this one. Both my issues started with 109 and moving to the UI integration from YAML I had setup over a year ago.

Screen Shot 2020-05-15 at 11 18 25 PM

Screenshot 2020-05-15 at 11 16 40 PM

bagelos commented 4 years ago

Hi there, Just adding to the list of people with recent issues with Vera integration. I have a Nero by Environexus controller. It is basically vera running UI7. It was working perfectly prior to recent update to HA (running in python venv on ubuntu). I was most recently running 109.2 version of HA, also tried update of pyvera as well. If I remove the integration, reboot then re-add, everything works for a while, then dies after maybe 10-15 mins? I've just done a full system update, updated HA to 109.6 (latest available 16/05/2020). So far - things seems ok? Will keep an eye on thngs and post logs if it loses connections again. Thanks gb

vangorra commented 4 years ago

I submitted a PR that I suspect will fix the issue of entities not getting updated. Since I have been unable to reproduce the issue, please test out the PR if you can. https://github.com/home-assistant/core/pull/35703

Based on the responses from many users, this issue appears to be caused by the controller not returning accurate incremental data or a race condition with threads could result in data being squashed. At any rate, this PR ensures that all status data is retrieved from the controller (not only incremental) and all this is done using proper hass event loops.