Core: Vera Hub Sensor States Not Updating in Home-Assistant

[JIOB]

Home Assistant release with the issue:

0.95.4

Last working Home Assistant release (if known):
0.94.4

Operating environment (Hass.io/Docker/Windows/etc.):

Docker
Component/platform:

https://www.home-assistant.io/components/vera/

Description of problem:
States not updated in Home-Assistant entities from Vera Hub since updating to 0.95. Possibly related to pyvera update #24289

Problem-relevant configuration.yaml entries and (fill out even if it seems unimportant):

vera:
  vera_controller_url: http://192.168.1.XX:3480/

Traceback (if applicable):

Additional information:

People seeing similar behaviour.

https://community.home-assistant.io/t/0-95-adguard-life360-plaato-airlock/123665/137?u=j_io_b

https://community.home-assistant.io/t/vera-plus-z-wave-hub-stops-updating-home-assistant-with-sensors-status/124776

[fgsalvador]

+1 Same issue 0.95.4

After re-starting Hassio, a couple of hours later motion sensors (Philio, Neo Coolcam, D-Link) stop updating event in Hassio. All automations based on them stop working. They are still reporting events at Vera Lite unit though.

I set the Vera component in debug logging and it shows normal polling activity until eventually it stops reporting and polling. It just stops reporting polling activity :frowning: Last lines in the logs are

2019-07-07 11:15:00 DEBUG (Vera Poll Thread) [pyvera] get_changed_devices() requesting payload {‘timeout’: 30, ‘minimumdelay’: 200, ‘id’: ‘lu_sdata’, ‘loadtime’: 1562385868, ‘dataversion’: 385901882}
2019-07-07 11:15:30 DEBUG (Vera Poll Thread) [pyvera.subscribe] Poll returned

Look as if HA gets a timeout when waiting for Vera to reply, it won’t continue polling. Is this the case? Is this the expected behaviour? If so, could it be tweaked by adjusting timeout, or not stopping polling even if a timeout is eventually got?

[basharfaraj]

This happened after updating hassio from 0.94 to 0.95. After removing the vera component from configuration.yaml restarting home assistant then adding it back, the hub would work fine and all the sensors would show in home assistant and their status would update all the time. but then after couple of hours the sensors would stop updating in home assistant and it just idles. the sensors are working fine in the vera UI but not in home assistant.

any help with this will be much appreciated.

Thank you

[hmmz77]

I'm having this exact same issue since 0.95 as well. All versions of 0.95 are affected. As above, after a few hours it seems the sensors attached to Vera stop reporting requiring a restart of HA to get them to work again. In 0.94 it's working flawlessly.

[jeroenjoosse]

Me too. Vera sensors update upon restart but stall from thereon untill next restart. I'm on 0.95.4. Had no problems in 0.94.

[fgsalvador]

@jeroenjoosse , @hmmz77 , @basharfaraj , @JIOB

Just to ensure we're all experiencing the same issue -and not different ones-, would you be able to gather and share some logs from your HA? I think that would help whoever can help troubleshooting the issue.

What I did to get mines was adding this at configuration.yaml and restart:

logger:
default: critical
logs:
pyvera: debug

And then, when your sensors stop updating in HA, you can just extract the last few lines from home-assistant.log file at your /config folder.

Thanks!

[hmmz77]

Unfortunately I've already rolled back to 0.94. I'll have to see when I have some free time to update and troubleshoot.

[jeroenjoosse]

Ah yes same here, rolled back after posting the above. I'll check tonight if the logs file allows me to see past the rollback.

[fgsalvador]

@jeroenjoosse I'm affraid logs are re-started once you reboot hassio. However, I decided to downgrade yesterday to 0.94 and it's now working flawlessly.

So for me looks to be the same issue, and my own logs couple help anyone with enought knowledge to anylize and eventualy fix this.

Thnks

[hmmz77]

@JIOB Can we label this as integration:vera?

[InkblotAdmirer]

This one may fix itself by just waiting for the next release. See this commit:

https://github.com/home-assistant/home-assistant/commit/5be695c49c99d9d1bcce5b5fc7601d8c1a1a6a1e

I updated the components/vera/manifest.json in my HA installation to use pyvera 0.3.2 as per that change, restarted, and I haven't had an issue since. Obviously there may be other issues with cherry-picking a change like this but I really didn't want to revert to 0.94 and deal with the google calendar authentications all over again.

[alanthewild]

Same problem here. I've turned on pyvera debugging and restarted so if it stops again I will post the logs.

[fgsalvador]

@InkblotAdmirer

Do you mean the issue is in fact related to that incorrect reference to pyvera release, and fix Will be included in 0.96.0?

Thanks in advance

[InkblotAdmirer]

@InkblotAdmirer

Do you mean the issue is in fact related to that incorrect reference to pyvera release, and fix Will be included in 0.96.0?

I can't say for sure but my guess is that some change in 0.95 is causing problems with the existing version of pyvera (0.3.1). The commit I linked updates pyvera to 0.3.2 and based on modifying my own system to use pyvera 0.3.2 with HA 0.95.4 I am concluding this will likely be automatically fixed if that commit is included in the next release.

[basharfaraj]

@InkblotAdmirer
Do you mean the issue is in fact related to that incorrect reference to pyvera release, and fix Will be included in 0.96.0?

I can't say for sure but my guess is that some change in 0.95 is causing problems with the existing version of pyvera (0.3.1). The commit I linked updates pyvera to 0.3.2 and based on modifying my own system to use pyvera 0.3.2 with HA 0.95.4 I am concluding this will likely be automatically fixed if that commit is included in the next release.

can you please tell us what you did and how exactly you did it ?

Thank you

[alanthewild]

@basharfaraj The version of pyvera that was included with HA 94.4 (last known working) was 0.2.45
The change for HA 95.x bumped pyvera to 0.3.1. Based on the commit that @InkblotAdmirer references, from what the pyvera project updates mention, seems there is a bug in 0.3.1 which is resolved in 0.3.2 (presumably it is able to handle null/missing values better). The change to 0.3.2 looks like it will be included in HA 96.x whenever that is available.

pyvera 0.3.2 is included in my docker image so I can just make the changes in the two files referenced in the commit @InkblotAdmirer linked and it should be good to go. You may or may not have 0.3.2 installed if you are not running this in docker?

To confirm you have pyvera 0.3.2 installed, run the following:
pip install pyvera
This should update/install 0.3.2 if you don't have it - no idea if this would break anything else though so try this at your own risk.

Changes to make:
Edit the two files referenced and change the pyvera version number from 0.3.1 to 0.3.2
homeassistant/components/vera/manifest.json
requirements_all.txt (this is in the parent folder next with the home assistant directory in my Docker image)

Or alternatively wait for HA 96.x to be released.
No guarantee the changes above will actually work but seems highly likely.

[fgsalvador]

Thans @alanthewilf for your delailed explanation!

Looks like this kind of modifications are not allowed for Hassio. Let's crossfingers with 0.96

[lielle1]

Well, I did all that and... it doenst work. 10 hours later Home Assistant stoped pulling states from vera.
Reverting to 0.94.

[InkblotAdmirer]

Well, I did all that and... it doenst work. 10 hours later Home Assistant stoped pulling states from vera.
Reverting to 0.94.

I only edited the version number in homeassistant/components/vera/manifest.json -- did you restart HA after the edit?

I am using hassbian and have also upgraded to python 3.7.3. No idea if this is related either but it cleaned up errors in my logs that I hadn't gotten around to troubleshooting yet so it may be possible?

In any case, if you've already reverted to 0.94 no reason to mess with this -- it's probably wiser to wait until 0.96 comes out and monitor reports on that version prior to upgrading.

[pensionado]

After this entry in the log:

Jul 13 06:45:18 raspberrypi2 hass[1571]: Exception in thread Vera Poll Thread:
Jul 13 06:45:18 raspberrypi2 hass[1571]: Traceback (most recent call last):
Jul 13 06:45:18 raspberrypi2 hass[1571]: File "/usr/lib/python3.5/threading.py", line 914, in _bootstrap_inner
Jul 13 06:45:18 raspberrypi2 hass[1571]: self.run()
Jul 13 06:45:18 raspberrypi2 hass[1571]: File "/usr/lib/python3.5/threading.py", line 862, in run
Jul 13 06:45:18 raspberrypi2 hass[1571]: self._target(self._args, *self._kwargs)
Jul 13 06:45:18 raspberrypi2 hass[1571]: File "/srv/homeassistant/lib/python3.5/site-packages/pyvera/subscribe.py", line 192, in _run_poll_server
Jul 13 06:45:18 raspberrypi2 hass[1571]: self._event(device_data, alert_data)
Jul 13 06:45:18 raspberrypi2 hass[1571]: File "/srv/homeassistant/lib/python3.5/site-packages/pyvera/subscribe.py", line 74, in _event
Jul 13 06:45:18 raspberrypi2 hass[1571]: [device_ids.add(int(device_data['id'])) for device_data in device_data_list]
Jul 13 06:45:18 raspberrypi2 hass[1571]: TypeError: 'NoneType' object is not iterable

All automation that was based on Vera device states were broken, including security devices. reverted back to 0.94.4

[lielle1]

Tried DEV version, still broken...

[alanthewild]

@lielle1 How is your home assistant installed and what is it running on? When you installed the DEV version, did you confirm your version of pyvera was 0.3.2? Did you run pip install pyvera? Or like @InkblotAdmirer have you upgraded to python 3.7.3 (which I believe would update your pyvera at the same time)?
As mentioned, mine is in a docker container so when HA is updated, the container contents are all updated at the same time so I'm always running the latest/correct versions of components (in theory).

I've been running this with the changes from the commit @InkblotAdmirer referenced and mine has been running happily since making those changes - 3 days so far (with a reboot about 36 hours ago to enable a new integration).

My only other change was to fix an Aeotec Dual Nano Switch that kept going offline previously - no idea if that had any impact on this - though it has made all my other z-wave devices more responsive :-).

[lielle1]

@lielle1 How is your home assistant installed and what is it running on? When you installed the DEV version, did you confirm your version of pyvera was 0.3.2? Did you run pip install pyvera? Or like @InkblotAdmirer have you upgraded to python 3.7.3 (which I believe would update your pyvera at the same time)?
As mentioned, mine is in a docker container so when HA is updated, the container contents are all updated at the same time so I'm always running the latest/correct versions of components (in theory).

I've been running this with the changes from the commit @InkblotAdmirer referenced and mine has been running happily since making those changes - 3 days so far (with a reboot about 36 hours ago to enable a new integration).

My only other change was to fix an Aeotec Dual Nano Switch that kept going offline previously - no idea if that had any impact on this - though it has made all my other z-wave devices more responsive :-).

HA runing from docker container, pyvera is 0.3.2.

[alanthewild]

@lielle1 In that case, bugger.
May be co-incidental that @InkblotAdmirer and I aren't having issues after making those changes to 0.3.2. I'm still on 95.4 and my vera sensors and switches are still updating at this point.

@brandond, any ideas on this? Appears to be affecting many people with vera. Looks like HA stops polling Vera for changes at some random interval.

[brandond]

Assuming folks are running into this:

Jul 13 06:45:18 raspberrypi2 hass[1571]: File "/srv/homeassistant/lib/python3.5/site-packages/pyvera/subscribe.py", line 192, in _run_poll_server
Jul 13 06:45:18 raspberrypi2 hass[1571]: self._event(device_data, alert_data)
Jul 13 06:45:18 raspberrypi2 hass[1571]: File "/srv/homeassistant/lib/python3.5/site-packages/pyvera/subscribe.py", line 74, in _event
Jul 13 06:45:18 raspberrypi2 hass[1571]: [device_ids.add(int(device_data['id'])) for device_data in device_data_list]
Jul 13 06:45:18 raspberrypi2 hass[1571]: TypeError: 'NoneType' object is not iterable

This should be fixed in pyvera 0.3.2 with this change. I hadn't noticed that the devices stopped polling after this happens, otherwise I would have requested an update to 0.3.2 sooner. I only have locks (no sensors/plugs/lights/etc) so the behavior may be different.

Note that if you see the error above you're not on 0.3.2, as the fragile list comprehensions are now on lines 80 and 81, not 74 and 75 as shown in the traceback. If someone who can confirm they're on 0.3.2 is still having polling break, then please grab some debug logs:

logger:
  default: critical
  logs:
    pyvera: debug

[alanthewild]

Thanks @brandond
Mine was actually working happily on 0.95.4 for a week or so until a reboot at which point it all went tits up almost immediately. Updating to 0.3.2 (based on the change you mention) for me seems to have resolved it. If it stops again I have debugging on so will share the logs. Fingers crossed it doesn't break again.

@lielle1 did you manage to capture any logs when yours stopped polling?
@pensionado your issue is definitely the one that @brandond mentions is fixed with 0.3.2

[lielle1]

@alanthewild

2019-07-15 17:28:00 DEBUG (Vera Poll Thread) [pyvera] get_changed_devices() requesting payload {'timeout': 30, 'minimumdelay': 200, 'id': 'lu_sdata', 'dataversion': 1, 'loadtime': 0}
2019-07-15 17:28:00 DEBUG (Vera Poll Thread) [pyvera] get_alerts() requesting payload {'LoadTime': 0, 'DataVersion': 1, 'id': 'status'}
2019-07-15 17:28:05 DEBUG (Vera Poll Thread) [pyvera.subscribe] Poll returned

HA stop polling from vera 1 minute after restart.
no problems on 0.94.4 install.

[brandond]

@lielle1 those are all normal startup messages. What happens after that? It seems like it's not picking up any devices, which is odd since none of that logic has been touched. You should see a SyncWorker thread subscribing to events for one or more devices.

2019-07-15 12:14:46 DEBUG (SyncWorker_12) [pyvera] DEBUG logging is ON
2019-07-15 12:14:46 DEBUG (Vera Poll Thread) [pyvera.subscribe] Polling for Vera changes
2019-07-15 12:14:46 DEBUG (Vera Poll Thread) [pyvera] get_changed_devices() requesting payload {'timeout': 30, 'minimumdelay': 200, 'id': 'lu_sdata', 'dataversion': 1, 'loadtime': 0}
2019-07-15 12:14:46 DEBUG (Vera Poll Thread) [pyvera] get_alerts() requesting payload {'LoadTime': 0, 'DataVersion': 1, 'id': 'status'}
2019-07-15 12:14:46 DEBUG (Vera Poll Thread) [pyvera.subscribe] Poll returned
2019-07-15 12:14:46 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for Front Door
2019-07-15 12:14:46 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for Back Door
2019-07-15 12:14:47 DEBUG (Vera Poll Thread) [pyvera.subscribe] Polling for Vera changes
2019-07-15 12:14:47 DEBUG (Vera Poll Thread) [pyvera] get_changed_devices() requesting payload {'timeout': 30, 'minimumdelay': 200, 'id': 'lu_sdata', 'loadtime': 1562921515, 'dataversion': 921515940}
2019-07-15 12:15:17 DEBUG (Vera Poll Thread) [pyvera.subscribe] Poll returned
2019-07-15 12:15:17 DEBUG (Vera Poll Thread) [pyvera.subscribe] No changes in poll interval
2019-07-15 12:15:18 DEBUG (Vera Poll Thread) [pyvera.subscribe] Polling for Vera changes
2019-07-15 12:15:18 DEBUG (Vera Poll Thread) [pyvera] get_changed_devices() requesting payload {'timeout': 30, 'minimumdelay': 200, 'id': 'lu_sdata', 'loadtime': 1562921515, 'dataversion': 921515940}
2019-07-15 12:15:48 DEBUG (Vera Poll Thread) [pyvera.subscribe] Poll returned
2019-07-15 12:15:48 DEBUG (Vera Poll Thread) [pyvera.subscribe] No changes in poll interval

If possible, could you check out a copy of pyvera from https://github.com/pavoni/pyvera and run a couple test commands:

• PYVERA_LOGLEVEL=DEBUG ./examples/list-devices.py -u http://YOUR_VERA_IP:3480/
• curl -s 'http://YOUR_VERA_IP:3480/data_request?id=lu_sdata&dataversion=1&loadtime=0&minimumdelay=200&timeout=30'

[lielle1]

@brandond

2019-07-16 07:01:24 DEBUG (SyncWorker_17) [pyvera] DEBUG logging is ON
2019-07-16 07:01:24 DEBUG (Vera Poll Thread) [pyvera.subscribe] Polling for Vera changes
2019-07-16 07:01:24 DEBUG (Vera Poll Thread) [pyvera] get_changed_devices() requesting payload {'timeout': 30, 'minimumdelay': 200, 'id': 'lu_sdata', 'dataversion': 1, 'loadtime': 0}
2019-07-16 07:01:24 DEBUG (Vera Poll Thread) [pyvera] get_alerts() requesting payload {'LoadTime': 0, 'DataVersion': 1, 'id': 'status'}
2019-07-16 07:01:28 DEBUG (Vera Poll Thread) [pyvera.subscribe] Poll returned
2019-07-16 07:01:31 DEBUG (SyncWorker_3) [pyvera.subscribe] Subscribing to events for zxt120
2019-07-16 07:01:31 DEBUG (SyncWorker_9) [pyvera.subscribe] Subscribing to events for roof sensor
2019-07-16 07:01:32 DEBUG (SyncWorker_14) [pyvera.subscribe] Subscribing to events for 3 in 1 sensor (temperature)
2019-07-16 07:01:32 DEBUG (SyncWorker_14) [pyvera.subscribe] Subscribing to events for 3 in 1 sensor (light)
2019-07-16 07:01:32 DEBUG (SyncWorker_14) [pyvera.subscribe] Subscribing to events for indoorx - Humidity
2019-07-16 07:01:32 DEBUG (SyncWorker_14) [pyvera.subscribe] Subscribing to events for indoorx - Pressure
2019-07-16 07:01:32 DEBUG (SyncWorker_14) [pyvera.subscribe] Subscribing to events for indoorx - Temperature
2019-07-16 07:01:32 DEBUG (SyncWorker_14) [pyvera.subscribe] Subscribing to events for outdoorx - Humidity
2019-07-16 07:01:32 DEBUG (SyncWorker_14) [pyvera.subscribe] Subscribing to events for outdoorx - Temperature
2019-07-16 07:01:32 DEBUG (SyncWorker_2) [pyvera.subscribe] Subscribing to events for Doorm
2019-07-16 07:01:32 DEBUG (SyncWorker_8) [pyvera.subscribe] Subscribing to events for roof carbon light
2019-07-16 07:01:32 DEBUG (SyncWorker_8) [pyvera.subscribe] Subscribing to events for ex
2019-07-16 07:01:32 DEBUG (SyncWorker_8) [pyvera.subscribe] Subscribing to events for Dining ledx
2019-07-16 07:01:32 DEBUG (SyncWorker_8) [pyvera.subscribe] Subscribing to events for Living Led
2019-07-16 07:01:32 DEBUG (SyncWorker_8) [pyvera.subscribe] Subscribing to events for salon
2019-07-16 07:01:32 DEBUG (SyncWorker_8) [pyvera.subscribe] Subscribing to events for led roof
2019-07-16 07:01:32 DEBUG (SyncWorker_8) [pyvera.subscribe] Subscribing to events for Fibaro Dimmer 2 1
2019-07-16 07:01:32 DEBUG (SyncWorker_8) [pyvera.subscribe] Subscribing to events for rgbx
2019-07-16 07:01:32 DEBUG (SyncWorker_8) [pyvera.subscribe] Subscribing to events for Blue
2019-07-16 07:01:32 DEBUG (SyncWorker_8) [pyvera.subscribe] Subscribing to events for Brightness
2019-07-16 07:01:32 DEBUG (SyncWorker_8) [pyvera.subscribe] Subscribing to events for Green
2019-07-16 07:01:32 DEBUG (SyncWorker_8) [pyvera.subscribe] Subscribing to events for Red
2019-07-16 07:01:32 DEBUG (SyncWorker_8) [pyvera.subscribe] Subscribing to events for White
2019-07-16 07:01:32 DEBUG (SyncWorker_8) [pyvera.subscribe] Subscribing to events for Stairway
2019-07-16 07:01:33 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for roof sensor
2019-07-16 07:01:33 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for game light
2019-07-16 07:01:33 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for Harmony Control
2019-07-16 07:01:33 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for HRM: Yes DVR
2019-07-16 07:01:33 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for vSwitch
2019-07-16 07:01:33 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for box light
2019-07-16 07:01:33 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for East Projector
2019-07-16 07:01:33 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for East top light
2019-07-16 07:01:33 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for East wall
2019-07-16 07:01:33 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for North wall light
2019-07-16 07:01:33 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for kitchen
2019-07-16 07:01:33 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for dining room light
2019-07-16 07:01:33 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for kitchen light
2019-07-16 07:01:33 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for Kitchen Led one
2019-07-16 07:01:33 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for Kitchen Led two
2019-07-16 07:01:33 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for Top North
2019-07-16 07:01:33 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for Washing machine
2019-07-16 07:01:33 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for Top projectors
2019-07-16 07:01:33 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for camera
2019-07-16 07:01:33 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for Roof in

this is the full startup log, No poll happen after this point.
pyvera react if i change state in HA not from vera.
I will try to run the pyvera commands later this day

[brandond]

@lielle1 are those all of your devices - it's not missing any? This is closer to what I'd expect to see. Did this not happen last time you checked the logs, or did you just not include it? I would expect to see something from the poll thread again soon after the subscriptions are complete. Can you post the full log for 5-10 minutes after startup without editing anything out?

[lielle1]

@brandond

2019-07-16 17:49:44 WARNING (MainThread) [homeassistant.loader] You are using a custom integration for hacs which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you do experience issues with Home Assistant.
2019-07-16 17:49:44 WARNING (MainThread) [homeassistant.loader] You are using a custom integration for alexa_media which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you do experience issues with Home Assistant.
2019-07-16 17:49:48 DEBUG (SyncWorker_6) [pyvera] DEBUG logging is ON
2019-07-16 17:49:48 DEBUG (Vera Poll Thread) [pyvera.subscribe] Polling for Vera changes
2019-07-16 17:49:48 DEBUG (Vera Poll Thread) [pyvera] get_changed_devices() requesting payload {'timeout': 30, 'minimumdelay': 200, 'id': 'lu_sdata', 'dataversion': 1, 'loadtime': 0}
2019-07-16 17:49:49 DEBUG (Vera Poll Thread) [pyvera] get_alerts() requesting payload {'LoadTime': 0, 'DataVersion': 1, 'id': 'status'}
2019-07-16 17:49:53 DEBUG (Vera Poll Thread) [pyvera.subscribe] Poll returned
2019-07-16 17:49:55 DEBUG (SyncWorker_15) [pyvera.subscribe] Subscribing to events for zxt120
2019-07-16 17:49:55 DEBUG (SyncWorker_5) [pyvera.subscribe] Subscribing to events for roof sensor
2019-07-16 17:49:56 DEBUG (SyncWorker_5) [pyvera.subscribe] Subscribing to events for Doorm
2019-07-16 17:49:56 DEBUG (SyncWorker_4) [pyvera.subscribe] Subscribing to events for roof carbon light
2019-07-16 17:49:56 DEBUG (SyncWorker_4) [pyvera.subscribe] Subscribing to events for ex
2019-07-16 17:49:56 DEBUG (SyncWorker_4) [pyvera.subscribe] Subscribing to events for Dining ledx
2019-07-16 17:49:56 DEBUG (SyncWorker_4) [pyvera.subscribe] Subscribing to events for Living Led
2019-07-16 17:49:56 DEBUG (SyncWorker_4) [pyvera.subscribe] Subscribing to events for salon
2019-07-16 17:49:56 DEBUG (SyncWorker_4) [pyvera.subscribe] Subscribing to events for led roof
2019-07-16 17:49:56 DEBUG (SyncWorker_4) [pyvera.subscribe] Subscribing to events for Fibaro Dimmer 2 1
2019-07-16 17:49:56 DEBUG (SyncWorker_4) [pyvera.subscribe] Subscribing to events for rgbx
2019-07-16 17:49:56 DEBUG (SyncWorker_4) [pyvera.subscribe] Subscribing to events for Blue
2019-07-16 17:49:56 DEBUG (SyncWorker_4) [pyvera.subscribe] Subscribing to events for Brightness
2019-07-16 17:49:56 DEBUG (SyncWorker_4) [pyvera.subscribe] Subscribing to events for Green
2019-07-16 17:49:56 DEBUG (SyncWorker_4) [pyvera.subscribe] Subscribing to events for Red
2019-07-16 17:49:56 DEBUG (SyncWorker_4) [pyvera.subscribe] Subscribing to events for White
2019-07-16 17:49:56 DEBUG (SyncWorker_4) [pyvera.subscribe] Subscribing to events for Stairway
2019-07-16 17:50:06 DEBUG (SyncWorker_13) [pyvera.subscribe] Subscribing to events for roof sensor
2019-07-16 17:50:06 DEBUG (SyncWorker_13) [pyvera.subscribe] Subscribing to events for game light
2019-07-16 17:50:06 DEBUG (SyncWorker_13) [pyvera.subscribe] Subscribing to events for Harmony Control
2019-07-16 17:50:06 DEBUG (SyncWorker_13) [pyvera.subscribe] Subscribing to events for HRM: Yes DVR
2019-07-16 17:50:06 DEBUG (SyncWorker_13) [pyvera.subscribe] Subscribing to events for vSwitch
2019-07-16 17:50:06 DEBUG (SyncWorker_13) [pyvera.subscribe] Subscribing to events for box light
2019-07-16 17:50:06 DEBUG (SyncWorker_13) [pyvera.subscribe] Subscribing to events for East Projector
2019-07-16 17:50:06 DEBUG (SyncWorker_13) [pyvera.subscribe] Subscribing to events for East top light
2019-07-16 17:50:06 DEBUG (SyncWorker_13) [pyvera.subscribe] Subscribing to events for East wall
2019-07-16 17:50:06 DEBUG (SyncWorker_13) [pyvera.subscribe] Subscribing to events for North wall light
2019-07-16 17:50:06 DEBUG (SyncWorker_13) [pyvera.subscribe] Subscribing to events for kitchen
2019-07-16 17:50:06 DEBUG (SyncWorker_13) [pyvera.subscribe] Subscribing to events for dining room light
2019-07-16 17:50:06 DEBUG (SyncWorker_13) [pyvera.subscribe] Subscribing to events for kitchen light
2019-07-16 17:50:06 DEBUG (SyncWorker_13) [pyvera.subscribe] Subscribing to events for Kitchen Led one
2019-07-16 17:50:06 DEBUG (SyncWorker_13) [pyvera.subscribe] Subscribing to events for Kitchen Led two
2019-07-16 17:50:06 DEBUG (SyncWorker_13) [pyvera.subscribe] Subscribing to events for Top North
2019-07-16 17:50:06 DEBUG (SyncWorker_13) [pyvera.subscribe] Subscribing to events for Washing machine
2019-07-16 17:50:06 DEBUG (SyncWorker_13) [pyvera.subscribe] Subscribing to events for Top projectors
2019-07-16 17:50:06 DEBUG (SyncWorker_13) [pyvera.subscribe] Subscribing to events for camera
2019-07-16 17:50:06 DEBUG (SyncWorker_13) [pyvera.subscribe] Subscribing to events for Roof in
2019-07-16 17:51:25 DEBUG (SyncWorker_13) [pyvera.subscribe] Subscribing to events for 3 in 1 sensor (temperature)
2019-07-16 17:51:25 DEBUG (SyncWorker_13) [pyvera.subscribe] Subscribing to events for 3 in 1 sensor (light)
2019-07-16 17:51:25 DEBUG (SyncWorker_13) [pyvera.subscribe] Subscribing to events for indoorx - Humidity
2019-07-16 17:51:25 DEBUG (SyncWorker_13) [pyvera.subscribe] Subscribing to events for indoorx - Pressure
2019-07-16 17:51:25 DEBUG (SyncWorker_13) [pyvera.subscribe] Subscribing to events for indoorx - Temperature
2019-07-16 17:51:25 DEBUG (SyncWorker_13) [pyvera.subscribe] Subscribing to events for outdoorx - Humidity
2019-07-16 17:51:25 DEBUG (SyncWorker_13) [pyvera.subscribe] Subscribing to events for outdoorx - Temperature

This is the full log after restart.
Unlike earlier version pre 0.95 polling accrued only after restart.

[alanthewild]

@lielle1 I find it interesting that we are both running HACS and Alexa_Media.
Is anyone else with this issue also using those custom integrations? Is it possible for one of those components to break the polling within HA for pyvera?

[lassej01]

Im not using HACS or Alexa. Still got the problem that it stop polls direct after a restart. 1 poll and then quiet.

[fgsalvador]

I had this issue (polling stopped after about two hours) and had to downgrade to 0.94.4 and worked flawlessly for a week in 0.94.4.

I decided to upgrade again to 0.95.4 to gather new logs and upload them in this chain....but it's already working with no issue for two days!

My setup is Hassio, also using Alexa, not HACS.

[brandond]

I am at somewhat of a loss here - I'm not sure how something as basic as a polling loop just does not work on your host. You're getting to the bottom of the first poll cycle, after which it should sleep for 1 second and then restart the loop with another blocking HTTP request.

I'm not familiar with how to use hass.io; I use native Docker myself. If I published a Docker image with some additional debug logging for pyvera would you be able to test it? What platform are you running hass.io on? I don't have a Pi so I can probably only do amd64 images.

[lielle1]

I'll be happy to test Docker image, I'm use HA docker on Synology NAS

[brandond]

@lielle1 Try with docker.io/brandond/home-assistant:pyvera-debug

[alanthewild]

I also am running this in docker on a Synology. And I have reverted to the vanilla 0.95.4 and everything is working happily at this point. Mine initially stopped polling after a restart same as @lielle1 (before I made the 0.3.2 changes)
@brandond I will try your docker image and see if I can get it to stop with multiple restarts later this evening (after my wife has started watching her programs as this thing is also our universal remote).

[lielle1]

Same results with: docker.io/brandond/home-assistant:pyvera-debug
1 poll and then nothing.

[jwater7]

0.96.0 was recently released that appears to include the 0.3.2 fix - everyone should be able to update and see if the issue is now resolved. I've updated and so far it appears to be working fine. I'll report back if I see any issues in the next couple days as that's how long it usually took for it to fail on 0.95.

[pi642s]

thank you jwater7! i have been having the same issue. will upgrade this weekend and see.

[lassej01]

Updated to 0.96.0 Just now. Problem is still there for me. doing an initial poll att startup, and then no more polls. I have a temp sensor that shows rising temperature in the sun so i can see pretty fast that it's not updating. I can see an error at startup:

2019-07-18 08:04:11 DEBUG (Vera Poll Thread) [pyvera] get_alerts() requesting payload {'LoadTime': 0, 'DataVersion': 1, 'id': 'status'}
2019-07-18 08:04:12 DEBUG (Vera Poll Thread) [pyvera.subscribe] Poll returned
Exception in thread Vera Poll Thread:
Traceback (most recent call last):
  File "C:\Users\lasse\AppData\Local\Programs\Python\Python36-32\lib\threading.py", line 916, in _bootstrap_inner
    self.run()
  File "C:\Users\lasse\AppData\Local\Programs\Python\Python36-32\lib\threading.py", line 864, in run
    self._target(*self._args, **self._kwargs)
  File "C:\Users\lasse\AppData\Roaming\.homeassistant\deps\Python36\site-packages\pyvera\subscribe.py", line 202, in _run_poll_server
    self._event(device_data, alert_data)
  File "C:\Users\lasse\AppData\Roaming\.homeassistant\deps\Python36\site-packages\pyvera\subscribe.py", line 81, in _event
    [device_ids.add(int(alert_data['PK_Device'])) for alert_data in device_alert_list]
  File "C:\Users\lasse\AppData\Roaming\.homeassistant\deps\Python36\site-packages\pyvera\subscribe.py", line 81, in <listcomp>
    [device_ids.add(int(alert_data['PK_Device'])) for alert_data in device_alert_list]
KeyError: 'PK_Device'

I only see that error in text in the console, not in the debug log.
2019-07-18 08:04:11 DEBUG (SyncWorker_3) [pyvera] DEBUG logging is ON
2019-07-18 08:04:11 DEBUG (Vera Poll Thread) [pyvera.subscribe] Polling for Vera changes
2019-07-18 08:04:11 DEBUG (Vera Poll Thread) [pyvera] get_changed_devices() requesting payload {'timeout': 30, 'minimumdelay': 200, 'id': 'lu_sdata', 'dataversion': 1, 'loadtime': 0}
2019-07-18 08:04:11 DEBUG (Vera Poll Thread) [pyvera] get_alerts() requesting payload {'LoadTime': 0, 'DataVersion': 1, 'id': 'status'}
2019-07-18 08:04:12 DEBUG (Vera Poll Thread) [pyvera.subscribe] Poll returned
2019-07-18 08:04:12 DEBUG (SyncWorker_3) [pyvera.subscribe] Subscribing to events for BrevlådaZ
2019-07-18 08:04:12 DEBUG (SyncWorker_3) [pyvera.subscribe] Subscribing to events for EYE_Uterum_IR
2019-07-18 08:04:12 DEBUG (SyncWorker_3) [pyvera.subscribe] Subscribing to events for Vardagsrumsdörr
2019-07-18 08:04:12 DEBUG (SyncWorker_3) [pyvera.subscribe] Subscribing to events for Magnetkontakt_B 1

.... took away a lot of devices that only fills the screen.

[brandond]

@lassej01 it looks like your status payload is missing some fields compared to the samples I've collected. Let me see if I can handle that better. Can you try the Docker image I referenced earlier?

@lielle1 can you provide logs? I didn't actually change anything at this point other than adding a bunch more debug messages, so I don't expect it to suddenly work, but the logs should tell us more about where its stopping. Also - are you collecting logs from the docker console, or just via the web debug log? As @lassej01 mentioned, some exceptions apparently don't show up in the debug log.

[lassej01]

@brandond I'm running on Windows. Have no docker.

[lielle1]

console log:
`

2019-07-18 10:53:46 | stdout | 2019-07-18 13:53:46 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for Top projectors
-- | -- | --
2019-07-18 10:53:46 | stdout | 2019-07-18 13:53:46 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for Washing machine
2019-07-18 10:53:46 | stdout | 2019-07-18 13:53:46 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for Top North
2019-07-18 10:53:46 | stdout | 2019-07-18 13:53:46 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for Kitchen Led two
2019-07-18 10:53:46 | stdout | 2019-07-18 13:53:46 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for Kitchen Led one
2019-07-18 10:53:46 | stdout | 2019-07-18 13:53:46 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for kitchen light
2019-07-18 10:53:46 | stdout | 2019-07-18 13:53:46 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for dining room light
2019-07-18 10:53:46 | stdout | 2019-07-18 13:53:46 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for kitchen
2019-07-18 10:53:46 | stdout | 2019-07-18 13:53:46 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for North wall light
2019-07-18 10:53:46 | stdout | 2019-07-18 13:53:46 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for East wall
2019-07-18 10:53:46 | stdout | 2019-07-18 13:53:46 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for East top light
2019-07-18 10:53:46 | stdout | 2019-07-18 13:53:46 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for East Projector
2019-07-18 10:53:46 | stdout | 2019-07-18 13:53:46 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for box light
2019-07-18 10:53:46 | stdout | 2019-07-18 13:53:46 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for game light
2019-07-18 10:53:46 | stdout | 2019-07-18 13:53:46 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for roof sensor
2019-07-18 10:53:36 | stdout | 2019-07-18 13:53:36 DEBUG (SyncWorker_7) [pyvera.subscribe] Subscribing to events for Stairway
2019-07-18 10:53:36 | stdout | 2019-07-18 13:53:36 DEBUG (SyncWorker_7) [pyvera.subscribe] Subscribing to events for White
2019-07-18 10:53:36 | stdout | 2019-07-18 13:53:36 DEBUG (SyncWorker_7) [pyvera.subscribe] Subscribing to events for Red
2019-07-18 10:53:36 | stdout | 2019-07-18 13:53:36 DEBUG (SyncWorker_7) [pyvera.subscribe] Subscribing to events for Green
2019-07-18 10:53:36 | stdout | 2019-07-18 13:53:36 DEBUG (SyncWorker_7) [pyvera.subscribe] Subscribing to events for Brightness
2019-07-18 10:53:36 | stdout | 2019-07-18 13:53:36 DEBUG (SyncWorker_7) [pyvera.subscribe] Subscribing to events for Blue
2019-07-18 10:53:36 | stdout | 2019-07-18 13:53:36 DEBUG (SyncWorker_7) [pyvera.subscribe] Subscribing to events for rgbx
2019-07-18 10:53:36 | stdout | 2019-07-18 13:53:36 DEBUG (SyncWorker_7) [pyvera.subscribe] Subscribing to events for Fibaro Dimmer 2 1
2019-07-18 10:53:36 | stdout | 2019-07-18 13:53:36 DEBUG (SyncWorker_7) [pyvera.subscribe] Subscribing to events for led roof
2019-07-18 10:53:36 | stdout | 2019-07-18 13:53:36 DEBUG (SyncWorker_7) [pyvera.subscribe] Subscribing to events for salon
2019-07-18 10:53:36 | stdout | 2019-07-18 13:53:36 DEBUG (SyncWorker_7) [pyvera.subscribe] Subscribing to events for Living Led
2019-07-18 10:53:36 | stdout | 2019-07-18 13:53:36 DEBUG (SyncWorker_7) [pyvera.subscribe] Subscribing to events for Dining ledx
2019-07-18 10:53:36 | stdout | 2019-07-18 13:53:36 DEBUG (SyncWorker_7) [pyvera.subscribe] Subscribing to events for ex
2019-07-18 10:53:36 | stdout | 2019-07-18 13:53:36 DEBUG (SyncWorker_7) [pyvera.subscribe] Subscribing to events for roof carbon light
2019-07-18 10:53:36 | stdout | 2019-07-18 13:53:36 DEBUG (SyncWorker_16) [pyvera.subscribe] Subscribing to events for Doorm
2019-07-18 10:53:35 | stdout | 2019-07-18 13:53:35 DEBUG (SyncWorker_0) [pyvera.subscribe] Subscribing to events for 3 in 1 sensor (light)
2019-07-18 10:53:35 | stdout | 2019-07-18 13:53:35 DEBUG (SyncWorker_0) [pyvera.subscribe] Subscribing to events for 3 in 1 sensor (temperature)
2019-07-18 10:53:35 | stdout | 2019-07-18 13:53:35 DEBUG (SyncWorker_0) [pyvera.subscribe] Subscribing to events for roof sensor
2019-07-18 10:53:35 | stdout | 2019-07-18 13:53:35 DEBUG (SyncWorker_3) [pyvera.subscribe] Subscribing to events for zxt120
2019-07-18 10:53:33 | stdout |  
2019-07-18 10:53:33 | stdout | KeyError: 'PK_Device'
2019-07-18 10:53:33 | stdout | [device_ids.add(int(alert_data['PK_Device'])) for alert_data in device_alert_list]
2019-07-18 10:53:33 | stdout | File "/usr/local/lib/python3.7/site-packages/pyvera/subscribe.py", line 81, in 
2019-07-18 10:53:33 | stdout | [device_ids.add(int(alert_data['PK_Device'])) for alert_data in device_alert_list]
2019-07-18 10:53:33 | stdout | File "/usr/local/lib/python3.7/site-packages/pyvera/subscribe.py", line 81, in _event
2019-07-18 10:53:33 | stdout | self._event(device_data, alert_data)
2019-07-18 10:53:33 | stdout | File "/usr/local/lib/python3.7/site-packages/pyvera/subscribe.py", line 207, in _run_poll_server
2019-07-18 10:53:33 | stdout | self._target(self._args, *self._kwargs)
2019-07-18 10:53:33 | stdout | File "/usr/local/lib/python3.7/threading.py", line 870, in run
2019-07-18 10:53:33 | stdout | self.run()
2019-07-18 10:53:33 | stdout | File "/usr/local/lib/python3.7/threading.py", line 926, in _bootstrap_inner
2019-07-18 10:53:33 | stdout | Traceback (most recent call last):
2019-07-18 10:53:33 | stdout | Exception in thread Vera Poll Thread:
2019-07-18 10:53:33 | stdout | 2019-07-18 13:53:33 DEBUG (Vera Poll Thread) [pyvera.subscribe] Changes found in poll interval; handling events
2019-07-18 10:53:33 | stdout | 2019-07-18 13:53:33 DEBUG (Vera Poll Thread) [pyvera.subscribe] Poll returned
2019-07-18 10:53:33 | stdout | 2019-07-18 13:53:33 DEBUG (Vera Poll Thread) [pyvera] get_alerts() requesting payload {'LoadTime': 0, 'DataVersion': 1, 'id': 'status'}
2019-07-18 10:53:33 | stdout | 2019-07-18 13:53:33 DEBUG (Vera Poll Thread) [pyvera.subscribe] Dataversion changed: {'dataversion': 1, 'loadtime': 0} -> {'loadtime': 1563345547, 'dataversion': 345578958}
2019-07-18 10:53:33 | stdout | 2019-07-18 13:53:33 DEBUG (Vera Poll Thread) [pyvera] get_changed_devices() requesting payload {'timeout': 30, 'minimumdelay': 200, 'id': 'lu_sdata', 'dataversion': 1, 'loadtime': 0}
2019-07-18 10:53:33 | stdout | 2019-07-18 13:53:33 DEBUG (Vera Poll Thread) [pyvera.subscribe] Polling for Vera changes
2019-07-18 10:53:33 | stdout | 2019-07-18 13:53:33 DEBUG (SyncWorker_0) [pyvera] DEBUG logging is ON
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (MainThread) [homeassistant.setup] Setting up logger
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (MainThread) [homeassistant.bootstrap] Setting up {'system_log', 'logger'}
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_19) [homeassistant.loader] Loaded websocket_api from homeassistant.components.websocket_api
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_17) [homeassistant.loader] Loaded system_log from homeassistant.components.system_log
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_5) [homeassistant.loader] Loaded onboarding from homeassistant.components.onboarding
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_7) [homeassistant.loader] Loaded lovelace from homeassistant.components.lovelace
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_16) [homeassistant.loader] Loaded auth from homeassistant.components.auth
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (MainThread) [homeassistant.setup] Setup of domain persistent_notification took 0.0 seconds.
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (MainThread) [homeassistant.setup] Setting up persistent_notification
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_14) [homeassistant.loader] Loaded zeroconf from homeassistant.components.zeroconf
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (MainThread) [homeassistant.setup] Setup of domain homeassistant took 0.0 seconds.
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (MainThread) [homeassistant.setup] Setting up homeassistant
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_13) [homeassistant.loader] Loaded webhook from homeassistant.components.webhook
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_15) [homeassistant.loader] Loaded api from homeassistant.components.api
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_11) [homeassistant.loader] Loaded configurator from homeassistant.components.configurator
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_2) [homeassistant.loader] Loaded persistent_notification from homeassistant.components.persistent_notification
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_3) [homeassistant.loader] Loaded device_tracker from homeassistant.components.device_tracker
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_0) [homeassistant.loader] Loaded mqtt from homeassistant.components.mqtt
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_1) [homeassistant.loader] Loaded homeassistant from homeassistant.components.homeassistant
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_18) [homeassistant.loader] Loaded script from homeassistant.components.script
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_12) [homeassistant.loader] Loaded group from homeassistant.components.group
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_19) [homeassistant.loader] Loaded ffmpeg from homeassistant.components.ffmpeg
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_4) [homeassistant.loader] Loaded vera from homeassistant.components.vera
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_17) [homeassistant.loader] Loaded map from homeassistant.components.map
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_8) [homeassistant.loader] Loaded history from homeassistant.components.history
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_5) [homeassistant.loader] Loaded scene from homeassistant.components.scene
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_6) [homeassistant.loader] Loaded zwave from homeassistant.components.zwave
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_7) [homeassistant.loader] Loaded kira from homeassistant.components.kira
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_10) [homeassistant.loader] Loaded netatmo from homeassistant.components.netatmo
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_16) [homeassistant.loader] Loaded switch from homeassistant.components.switch
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_9) [homeassistant.loader] Loaded ps4 from homeassistant.components.ps4
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_14) [homeassistant.loader] Loaded logger from homeassistant.components.logger
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_15) [homeassistant.loader] Loaded http from homeassistant.components.http
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_13) [homeassistant.loader] Loaded recorder from homeassistant.components.recorder
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_3) [homeassistant.loader] Loaded shell_command from homeassistant.components.shell_command
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_11) [homeassistant.loader] Loaded xiaomi_aqara from homeassistant.components.xiaomi_aqara
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_2) [homeassistant.loader] Loaded camera from homeassistant.components.camera
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_1) [homeassistant.loader] Loaded zone from homeassistant.components.zone
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_12) [homeassistant.loader] Loaded notify from homeassistant.components.notify
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_0) [homeassistant.loader] Loaded frontend from homeassistant.components.frontend
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_17) [homeassistant.loader] Loaded media_player from homeassistant.components.media_player
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_4) [homeassistant.loader] Loaded system_health from homeassistant.components.system_health
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_18) [homeassistant.loader] Loaded updater from homeassistant.components.updater
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_4) [homeassistant.loader] Loaded logbook from homeassistant.components.logbook
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_10) [homeassistant.loader] Loaded automation from homeassistant.components.automation
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_16) [homeassistant.loader] Loaded sensor from homeassistant.components.sensor
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 WARNING (MainThread) [homeassistant.loader] You are using a custom integration for alexa_media which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you do experience issues with Home Assistant.
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 WARNING (MainThread) [homeassistant.loader] You are using a custom integration for hacs which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you do experience issues with Home Assistant.
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_8) [homeassistant.loader] Loaded config from homeassistant.components.config
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_9) [homeassistant.loader] Loaded owntracks from homeassistant.components.owntracks
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_12) [homeassistant.loader] Loaded ios from homeassistant.components.ios
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_1) [homeassistant.loader] Loaded wake_on_lan from homeassistant.components.wake_on_lan
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_7) [homeassistant.loader] Loaded sabnzbd from homeassistant.components.sabnzbd
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_0) [homeassistant.loader] Loaded remote from homeassistant.components.remote
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_5) [homeassistant.loader] Loaded sonarr_upcoming_media from custom_components.sonarr_upcoming_media
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_6) [homeassistant.loader] Loaded hacs from custom_components.hacs
2019-07-18 10:53:29 | stdout | 2019-07-18 13:53:29 INFO (SyncWorker_6) [homeassistant.loader] Loaded alexa_media from custom_components.alexa_media
2019-07-18 10:53:28 | stdout | 2019-07-18 13:53:28 INFO (SyncWorker_0) [homeassistant.config] Upgrading configuration directory from 0.94.4 to 0.97.0.dev0
2019-07-18 10:53:28 | stdout | Config directory: /config
2019-07-18 04:14:41 | stdout | 
2019-07-18 04:14:35 | stdout | 2019-07-18 07:14:35 INFO (SyncWorker_12) [pyvera.subscribe] Terminated thread
2019-07-18 04:00:24 | stdout | 2019-07-18 07:00:24 DEBUG (SyncWorker_13) [pyvera.subscribe] Subscribing to events for Top projectors
2019-07-18 04:00:24 | stdout | 2019-07-18 07:00:24 DEBUG (SyncWorker_13) [pyvera.subscribe] Subscribing to events for Washing machine
2019-07-18 04:00:24 | stdout | 2019-07-18 07:00:24 DEBUG (SyncWorker_13) [pyvera.subscribe] Subscribing to events for Top North
2019-07-18 04:00:24 | stdout | 2019-07-18 07:00:24 DEBUG (SyncWorker_13) [pyvera.subscribe] Subscribing to events for Kitchen Led two
2019-07-18 04:00:24 | stdout | 2019-07-18 07:00:24 DEBUG (SyncWorker_13) [pyvera.subscribe] Subscribing to events for Kitchen Led one
2019-07-18 04:00:24 | stdout | 2019-07-18 07:00:24 DEBUG (SyncWorker_13) [pyvera.subscribe] Subscribing to events for kitchen light
2019-07-18 04:00:24 | stdout | 2019-07-18 07:00:24 DEBUG (SyncWorker_13) [pyvera.subscribe] Subscribing to events for dining room light
2019-07-18 04:00:24 | stdout | 2019-07-18 07:00:24 DEBUG (SyncWorker_13) [pyvera.subscribe] Subscribing to events for kitchen
2019-07-18 04:00:24 | stdout | 2019-07-18 07:00:24 DEBUG (SyncWorker_13) [pyvera.subscribe] Subscribing to events for North wall light
2019-07-18 04:00:24 | stdout | 2019-07-18 07:00:24 DEBUG (SyncWorker_13) [pyvera.subscribe] Subscribing to events for East wall
2019-07-18 04:00:24 | stdout | 2019-07-18 07:00:24 DEBUG (SyncWorker_13) [pyvera.subscribe] Subscribing to events for East top light
2019-07-18 04:00:24 | stdout | 2019-07-18 07:00:24 DEBUG (SyncWorker_13) [pyvera.subscribe] Subscribing to events for East Projector
2019-07-18 04:00:24 | stdout | 2019-07-18 07:00:24 DEBUG (SyncWorker_13) [pyvera.subscribe] Subscribing to events for box light
2019-07-18 04:00:24 | stdout | 2019-07-18 07:00:24 DEBUG (SyncWorker_13) [pyvera.subscribe] Subscribing to events for game light
2019-07-18 04:00:24 | stdout | 2019-07-18 07:00:24 DEBUG (SyncWorker_13) [pyvera.subscribe] Subscribing to events for roof sensor
2019-07-18 04:00:14 | stdout | 2019-07-18 07:00:14 DEBUG (SyncWorker_8) [pyvera.subscribe] Subscribing to events for 3 in 1 sensor (light)
2019-07-18 04:00:14 | stdout | 2019-07-18 07:00:14 DEBUG (SyncWorker_8) [pyvera.subscribe] Subscribing to events for 3 in 1 sensor (temperature)
2019-07-18 04:00:12 | stdout | 2019-07-18 07:00:12 DEBUG (SyncWorker_4) [pyvera.subscribe] Subscribing to events for zxt120
2019-07-18 04:00:12 | stdout | 2019-07-18 07:00:12 DEBUG (SyncWorker_19) [pyvera.subscribe] Subscribing to events for Stairway
2019-07-18 04:00:12 | stdout | 2019-07-18 07:00:12 DEBUG (SyncWorker_12) [pyvera.subscribe] Subscribing to events for Doorm
2019-07-18 04:00:12 | stdout | 2019-07-18 07:00:12 DEBUG (SyncWorker_19) [pyvera.subscribe] Subscribing to events for White
2019-07-18 04:00:12 | stdout | 2019-07-18 07:00:12 DEBUG (SyncWorker_19) [pyvera.subscribe] Subscribing to events for Red
2019-07-18 04:00:12 | stdout | 2019-07-18 07:00:12 DEBUG (SyncWorker_19) [pyvera.subscribe] Subscribing to events for Green
2019-07-18 04:00:12 | stdout | 2019-07-18 07:00:12 DEBUG (SyncWorker_19) [pyvera.subscribe] Subscribing to events for Brightness
2019-07-18 04:00:12 | stdout | 2019-07-18 07:00:12 DEBUG (SyncWorker_19) [pyvera.subscribe] Subscribing to events for Blue
2019-07-18 04:00:12 | stdout | 2019-07-18 07:00:12 DEBUG (SyncWorker_19) [pyvera.subscribe] Subscribing to events for rgbx
2019-07-18 04:00:12 | stdout | 2019-07-18 07:00:12 DEBUG (SyncWorker_19) [pyvera.subscribe] Subscribing to events for Fibaro Dimmer 2 1
2019-07-18 04:00:12 | stdout | 2019-07-18 07:00:12 DEBUG (SyncWorker_19) [pyvera.subscribe] Subscribing to events for led roof
2019-07-18 04:00:12 | stdout | 2019-07-18 07:00:12 DEBUG (SyncWorker_19) [pyvera.subscribe] Subscribing to events for salon
2019-07-18 04:00:12 | stdout | 2019-07-18 07:00:12 DEBUG (SyncWorker_19) [pyvera.subscribe] Subscribing to events for Living Led
2019-07-18 04:00:12 | stdout | 2019-07-18 07:00:12 DEBUG (SyncWorker_19) [pyvera.subscribe] Subscribing to events for Dining ledx
2019-07-18 04:00:12 | stdout | 2019-07-18 07:00:12 DEBUG (SyncWorker_19) [pyvera.subscribe] Subscribing to events for ex
2019-07-18 04:00:12 | stdout | 2019-07-18 07:00:12 DEBUG (SyncWorker_19) [pyvera.subscribe] Subscribing to events for roof carbon light
2019-07-18 04:00:12 | stdout | 2019-07-18 07:00:12 DEBUG (SyncWorker_2) [pyvera.subscribe] Subscribing to events for roof sensor
2019-07-18 04:00:11 | stdout |  
2019-07-18 04:00:11 | stdout | KeyError: 'PK_Device'
2019-07-18 04:00:11 | stdout | [device_ids.add(int(alert_data['PK_Device'])) for alert_data in device_alert_list]
2019-07-18 04:00:11 | stdout | File "/usr/local/lib/python3.7/site-packages/pyvera/subscribe.py", line 81, in 
2019-07-18 04:00:11 | stdout | [device_ids.add(int(alert_data['PK_Device'])) for alert_data in device_alert_list]
2019-07-18 04:00:11 | stdout | File "/usr/local/lib/python3.7/site-packages/pyvera/subscribe.py", line 81, in _event
2019-07-18 04:00:11 | stdout | self._event(device_data, alert_data)
2019-07-18 04:00:11 | stdout | File "/usr/local/lib/python3.7/site-packages/pyvera/subscribe.py", line 207, in _run_poll_server
2019-07-18 04:00:11 | stdout | self._target(self._args, *self._kwargs)
2019-07-18 04:00:11 | stdout | File "/usr/local/lib/python3.7/threading.py", line 870, in run
2019-07-18 04:00:11 | stdout | self.run()
2019-07-18 04:00:11 | stdout | File "/usr/local/lib/python3.7/threading.py", line 926, in _bootstrap_inner
2019-07-18 04:00:11 | stdout | Traceback (most recent call last):
2019-07-18 04:00:11 | stdout | Exception in thread Vera Poll Thread:
2019-07-18 04:00:11 | stdout | 2019-07-18 07:00:11 DEBUG (Vera Poll Thread) [pyvera.subscribe] Changes found in poll interval; handling events
2019-07-18 04:00:11 | stdout | 2019-07-18 07:00:11 DEBUG (Vera Poll Thread) [pyvera.subscribe] Poll returned
2019-07-18 04:00:11 | stdout | 2019-07-18 07:00:11 DEBUG (Vera Poll Thread) [pyvera] get_alerts() requesting payload {'LoadTime': 0, 'DataVersion': 1, 'id': 'status'}
2019-07-18 04:00:11 | stdout | 2019-07-18 07:00:11 DEBUG (Vera Poll Thread) [pyvera.subscribe] Dataversion changed: {'dataversion': 1, 'loadtime': 0} -> {'loadtime': 1563345547, 'dataversion': 345572350}
2019-07-18 04:00:11 | stdout | 2019-07-18 07:00:11 DEBUG (Vera Poll Thread) [pyvera] get_changed_devices() requesting payload {'timeout': 30, 'minimumdelay': 200, 'id': 'lu_sdata', 'dataversion': 1, 'loadtime': 0}
2019-07-18 04:00:11 | stdout | 2019-07-18 07:00:11 DEBUG (Vera Poll Thread) [pyvera.subscribe] Polling for Vera changes
2019-07-18 04:00:11 | stdout | 2019-07-18 07:00:11 DEBUG (SyncWorker_17) [pyvera] DEBUG logging is ON
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (MainThread) [homeassistant.setup] Setting up logger
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (MainThread) [homeassistant.bootstrap] Setting up {'logger', 'system_log'}
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (SyncWorker_1) [homeassistant.loader] Loaded websocket_api from homeassistant.components.websocket_api
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (SyncWorker_13) [homeassistant.loader] Loaded system_log from homeassistant.components.system_log
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (SyncWorker_6) [homeassistant.loader] Loaded onboarding from homeassistant.components.onboarding
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (SyncWorker_15) [homeassistant.loader] Loaded lovelace from homeassistant.components.lovelace
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (SyncWorker_16) [homeassistant.loader] Loaded zeroconf from homeassistant.components.zeroconf
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (SyncWorker_7) [homeassistant.loader] Loaded auth from homeassistant.components.auth
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (MainThread) [homeassistant.setup] Setup of domain persistent_notification took 0.0 seconds.
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (MainThread) [homeassistant.setup] Setting up persistent_notification
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (MainThread) [homeassistant.setup] Setup of domain homeassistant took 0.0 seconds.
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (MainThread) [homeassistant.setup] Setting up homeassistant
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (SyncWorker_9) [homeassistant.loader] Loaded api from homeassistant.components.api
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (SyncWorker_14) [homeassistant.loader] Loaded webhook from homeassistant.components.webhook
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (SyncWorker_12) [homeassistant.loader] Loaded device_tracker from homeassistant.components.device_tracker
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (SyncWorker_19) [homeassistant.loader] Loaded configurator from homeassistant.components.configurator
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (SyncWorker_5) [homeassistant.loader] Loaded ps4 from homeassistant.components.ps4
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (SyncWorker_11) [homeassistant.loader] Loaded persistent_notification from homeassistant.components.persistent_notification
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (SyncWorker_8) [homeassistant.loader] Loaded mqtt from homeassistant.components.mqtt
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (SyncWorker_10) [homeassistant.loader] Loaded ffmpeg from homeassistant.components.ffmpeg
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (SyncWorker_0) [homeassistant.loader] Loaded homeassistant from homeassistant.components.homeassistant
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (SyncWorker_18) [homeassistant.loader] Loaded sensor from homeassistant.components.sensor
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (SyncWorker_1) [homeassistant.loader] Loaded script from homeassistant.components.script
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (SyncWorker_2) [homeassistant.loader] Loaded switch from homeassistant.components.switch
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (SyncWorker_13) [homeassistant.loader] Loaded vera from homeassistant.components.vera
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (SyncWorker_3) [homeassistant.loader] Loaded media_player from homeassistant.components.media_player
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (SyncWorker_6) [homeassistant.loader] Loaded logbook from homeassistant.components.logbook
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (SyncWorker_4) [homeassistant.loader] Loaded notify from homeassistant.components.notify
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (SyncWorker_15) [homeassistant.loader] Loaded camera from homeassistant.components.camera
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (SyncWorker_7) [homeassistant.loader] Loaded automation from homeassistant.components.automation
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (SyncWorker_9) [homeassistant.loader] Loaded updater from homeassistant.components.updater
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (SyncWorker_16) [homeassistant.loader] Loaded frontend from homeassistant.components.frontend
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (SyncWorker_12) [homeassistant.loader] Loaded system_health from homeassistant.components.system_health
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (SyncWorker_17) [homeassistant.loader] Loaded ios from homeassistant.components.ios
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (SyncWorker_14) [homeassistant.loader] Loaded map from homeassistant.components.map
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (SyncWorker_0) [homeassistant.loader] Loaded config from homeassistant.components.config
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (SyncWorker_8) [homeassistant.loader] Loaded history from homeassistant.components.history
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (SyncWorker_6) [homeassistant.loader] Loaded recorder from homeassistant.components.recorder
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (SyncWorker_1) [homeassistant.loader] Loaded xiaomi_aqara from homeassistant.components.xiaomi_aqara
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (SyncWorker_3) [homeassistant.loader] Loaded owntracks from homeassistant.components.owntracks
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (SyncWorker_13) [homeassistant.loader] Loaded kira from homeassistant.components.kira
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (SyncWorker_12) [homeassistant.loader] Loaded scene from homeassistant.components.scene
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (SyncWorker_17) [homeassistant.loader] Loaded zone from homeassistant.components.zone
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 WARNING (MainThread) [homeassistant.loader] You are using a custom integration for alexa_media which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you do experience issues with Home Assistant.
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (SyncWorker_17) [homeassistant.loader] Loaded http from homeassistant.components.http
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (SyncWorker_10) [homeassistant.loader] Loaded sabnzbd from homeassistant.components.sabnzbd
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (SyncWorker_2) [homeassistant.loader] Loaded remote from homeassistant.components.remote
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 WARNING (MainThread) [homeassistant.loader] You are using a custom integration for hacs which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you do experience issues with Home Assistant.
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (SyncWorker_2) [homeassistant.loader] Loaded wake_on_lan from homeassistant.components.wake_on_lan
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (SyncWorker_7) [homeassistant.loader] Loaded group from homeassistant.components.group
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (SyncWorker_0) [homeassistant.loader] Loaded logger from homeassistant.components.logger
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (SyncWorker_6) [homeassistant.loader] Loaded netatmo from homeassistant.components.netatmo
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (SyncWorker_0) [homeassistant.loader] Loaded zwave from homeassistant.components.zwave
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:37 INFO (SyncWorker_10) [homeassistant.loader] Loaded shell_command from homeassistant.components.shell_command
2019-07-18 03:59:37 | stdout | 2019-07-18 06:59:36 INFO (SyncWorker_4) [homeassistant.loader] Loaded sonarr_upcoming_media from custom_components.sonarr_upcoming_media
2019-07-18 03:59:36 | stdout | 2019-07-18 06:59:36 INFO (SyncWorker_7) [homeassistant.loader] Loaded hacs from custom_components.hacs
2019-07-18 03:59:36 | stdout | 2019-07-18 06:59:36 INFO (SyncWorker_3) [homeassistant.loader] Loaded alexa_media from custom_components.alexa_media
2019-07-18 03:59:36 | stdout | Config directory: /config

`

[lielle1]

HA log:

019-07-18 13:53:29 WARNING (MainThread) [homeassistant.loader] You are using a custom integration for hacs which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you do experience issues with Home Assistant.
2019-07-18 13:53:29 WARNING (MainThread) [homeassistant.loader] You are using a custom integration for alexa_media which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you do experience issues with Home Assistant.
2019-07-18 13:53:33 DEBUG (SyncWorker_0) [pyvera] DEBUG logging is ON
2019-07-18 13:53:33 DEBUG (Vera Poll Thread) [pyvera.subscribe] Polling for Vera changes
2019-07-18 13:53:33 DEBUG (Vera Poll Thread) [pyvera] get_changed_devices() requesting payload {'timeout': 30, 'minimumdelay': 200, 'id': 'lu_sdata', 'dataversion': 1, 'loadtime': 0}
2019-07-18 13:53:33 DEBUG (Vera Poll Thread) [pyvera.subscribe] Dataversion changed: {'dataversion': 1, 'loadtime': 0} -> {'loadtime': 1563345547, 'dataversion': 345578958}
2019-07-18 13:53:33 DEBUG (Vera Poll Thread) [pyvera] get_alerts() requesting payload {'LoadTime': 0, 'DataVersion': 1, 'id': 'status'}
2019-07-18 13:53:33 DEBUG (Vera Poll Thread) [pyvera.subscribe] Poll returned
2019-07-18 13:53:33 DEBUG (Vera Poll Thread) [pyvera.subscribe] Changes found in poll interval; handling events
2019-07-18 13:53:35 DEBUG (SyncWorker_3) [pyvera.subscribe] Subscribing to events for zxt120
2019-07-18 13:53:35 DEBUG (SyncWorker_0) [pyvera.subscribe] Subscribing to events for roof sensor
2019-07-18 13:53:35 DEBUG (SyncWorker_0) [pyvera.subscribe] Subscribing to events for 3 in 1 sensor (temperature)
2019-07-18 13:53:35 DEBUG (SyncWorker_0) [pyvera.subscribe] Subscribing to events for 3 in 1 sensor (light)
2019-07-18 13:53:36 DEBUG (SyncWorker_16) [pyvera.subscribe] Subscribing to events for Doorm
2019-07-18 13:53:36 DEBUG (SyncWorker_7) [pyvera.subscribe] Subscribing to events for roof carbon light
2019-07-18 13:53:36 DEBUG (SyncWorker_7) [pyvera.subscribe] Subscribing to events for ex
2019-07-18 13:53:36 DEBUG (SyncWorker_7) [pyvera.subscribe] Subscribing to events for Dining ledx
2019-07-18 13:53:36 DEBUG (SyncWorker_7) [pyvera.subscribe] Subscribing to events for Living Led
2019-07-18 13:53:36 DEBUG (SyncWorker_7) [pyvera.subscribe] Subscribing to events for salon
2019-07-18 13:53:36 DEBUG (SyncWorker_7) [pyvera.subscribe] Subscribing to events for led roof
2019-07-18 13:53:36 DEBUG (SyncWorker_7) [pyvera.subscribe] Subscribing to events for Fibaro Dimmer 2 1
2019-07-18 13:53:36 DEBUG (SyncWorker_7) [pyvera.subscribe] Subscribing to events for rgbx
2019-07-18 13:53:36 DEBUG (SyncWorker_7) [pyvera.subscribe] Subscribing to events for Blue
2019-07-18 13:53:36 DEBUG (SyncWorker_7) [pyvera.subscribe] Subscribing to events for Brightness
2019-07-18 13:53:36 DEBUG (SyncWorker_7) [pyvera.subscribe] Subscribing to events for Green
2019-07-18 13:53:36 DEBUG (SyncWorker_7) [pyvera.subscribe] Subscribing to events for Red
2019-07-18 13:53:36 DEBUG (SyncWorker_7) [pyvera.subscribe] Subscribing to events for White
2019-07-18 13:53:36 DEBUG (SyncWorker_7) [pyvera.subscribe] Subscribing to events for Stairway
2019-07-18 13:53:46 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for roof sensor
2019-07-18 13:53:46 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for game light
2019-07-18 13:53:46 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for box light
2019-07-18 13:53:46 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for East Projector
2019-07-18 13:53:46 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for East top light
2019-07-18 13:53:46 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for East wall
2019-07-18 13:53:46 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for North wall light
2019-07-18 13:53:46 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for kitchen
2019-07-18 13:53:46 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for dining room light
2019-07-18 13:53:46 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for kitchen light
2019-07-18 13:53:46 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for Kitchen Led one
2019-07-18 13:53:46 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for Kitchen Led two
2019-07-18 13:53:46 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for Top North
2019-07-18 13:53:46 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for Washing machine
2019-07-18 13:53:46 DEBUG (SyncWorker_18) [pyvera.subscribe] Subscribing to events for Top projectors

[lielle1]

sorry for the long log.
here's the relevant exception (i think):

KeyError: 'PK_Device'
--
2019-07-18 04:00:11 | stdout | [device_ids.add(int(alert_data['PK_Device'])) for alert_data in device_alert_list]
2019-07-18 04:00:11 | stdout | File "/usr/local/lib/python3.7/site-packages/pyvera/subscribe.py", line 81, in <listcomp>
2019-07-18 04:00:11 | stdout | [device_ids.add(int(alert_data['PK_Device'])) for alert_data in device_alert_list]
2019-07-18 04:00:11 | stdout | File "/usr/local/lib/python3.7/site-packages/pyvera/subscribe.py", line 81, in _event
2019-07-18 04:00:11 | stdout | self._event(device_data, alert_data)
2019-07-18 04:00:11 | stdout | File "/usr/local/lib/python3.7/site-packages/pyvera/subscribe.py", line 207, in _run_poll_server
2019-07-18 04:00:11 | stdout | self._target(*self._args, **self._kwargs)
2019-07-18 04:00:11 | stdout | File "/usr/local/lib/python3.7/threading.py", line 870, in run
2019-07-18 04:00:11 | stdout | self.run()
2019-07-18 04:00:11 | stdout | File "/usr/local/lib/python3.7/threading.py", line 926, in _bootstrap_inner
2019-07-18 04:00:11 | stdout | Traceback (most recent call last):
2019-07-18 04:00:11 | stdout | Exception in thread Vera Poll Thread:

[fgsalvador]

Guys,

not sure if this may help. It failed for me at 0.95.4. After several attempts with 0.95.4, I decided to downgrade to 0.94.4 and worked fine for a week. Then I upgraded again to 0.95.4 and it worked fine....No explanation for that. I'm now at 0.96 and also works fine.

This started to fail for me at 0.94.4 when I included some new motion sensors (Neo Coolcam) at my Vera Lite. May that be the case that the issue is related to the inclussion of new devices, for whatever reason?

[lassej01]

@fgsalvador HI, have tried to downgrade several time and wn im on 94.4 it works again. Update to 0.95.x does not work (neither do 0.96.0 so far)

[fgsalvador]

@lassej01 for me this failed initially at 94.4 -> it worked fine for a couple of hours after restating, and then failed.

I remember my logs showed something similar to the ones provided by @pensionado but I lost my logs when I downgraded. Probably we may be facing different issues....

Jul 13 06:45:18 raspberrypi2 hass[1571]: Exception in thread Vera Poll Thread:
Jul 13 06:45:18 raspberrypi2 hass[1571]: Traceback (most recent call last):
Jul 13 06:45:18 raspberrypi2 hass[1571]: File "/usr/lib/python3.5/threading.py", line 914, in _bootstrap_inner
Jul 13 06:45:18 raspberrypi2 hass[1571]: self.run()
Jul 13 06:45:18 raspberrypi2 hass[1571]: File "/usr/lib/python3.5/threading.py", line 862, in run
Jul 13 06:45:18 raspberrypi2 hass[1571]: self._target(*self._args, **self._kwargs)
Jul 13 06:45:18 raspberrypi2 hass[1571]: File "/srv/homeassistant/lib/python3.5/site-packages/pyvera/subscribe.py", line 192, in _run_poll_server
Jul 13 06:45:18 raspberrypi2 hass[1571]: self._event(device_data, alert_data)
Jul 13 06:45:18 raspberrypi2 hass[1571]: File "/srv/homeassistant/lib/python3.5/site-packages/pyvera/subscribe.py", line 74, in _event
Jul 13 06:45:18 raspberrypi2 hass[1571]: [device_ids.add(int(device_data['id'])) for device_data in device_data_list]
Jul 13 06:45:18 raspberrypi2 hass[1571]: TypeError: 'NoneType' object is not iterable

[lassej01]

Just reinstalled the whole environment with python 3.7 as a base. 0.96.0. Same error as before regarding vera polling. Downgraded to 0.94.4 and everything started to work again. (Pyvera==0.32.0), Requests==2.22.0, urllib3==1.24.3, certifi==2019.6.16, idna==2.8, chardet=3.0.4, aiohttp==3.5.4. The versions of the software that's installed that Request is depending on, and the version of request that pyvera is depending on.

[lassej01]

Tried to track all files that has changed between 0.94.4 and 0.95.The files above incluided. Have toggled versions and restarted hass on 0.96 and hoped that some of those files could cause this. But no success. The only file i can see now that i havn't tried to play with is homeassistant itself, the error message with keyerror "PK_Device" is showing up all the time on 0.95.4 and 0.96.1, but not on 0.94.4.

[lielle1]

Tried to track all files that has changed between 0.94.4 and 0.95.The files above incluided. Have toggled versions and restarted hass on 0.96 and hoped that some of those files could cause this. But no success. The only file i can see now that i havn't tried to play with is homeassistant itself, the error message with keyerror "PK_Device" is showing up all the time on 0.95.4 and 0.96.1, but not on 0.94.4.

Same here

[hmmz77]

Updated to 0.96 on hassio, seems to be all good so far.. Previously on 0.95 vera would have failed by now.

[jwater7]

Wow, there are some ridiculously long posts here.

Anyway, long story short, for most of us the issue is probably resolved by upgrading to 0.96.0 I’ve been running it for a while with no issues - thanks!

[surfarn]

I updated to 0.96.2 and I still have problems. I have power plugs that measures power consumption. They only updates with new values right after restart.

[jwater7]

I have all z-wave devices. Can some of you that are having issues list the devices that are connected? That might the difference. It may also be the difference between docker and a Windows installation. Let us know if you’re on windows and not having the issue.

[surfarn]

I have neo Coolcam zwave devices (Power plugs) and loads of rfxtrx 433 devices. Ubuntu docker install. Using hyper-v.

[lassej01]

Windows, Lots of Zwave sensors, switches, covers , different brands and rfxtrx devices.

[brandond]

Thanks @lielle1 - it appears that some alerts are missing the PK_Device attribute that ties the alert to a device ID. The fact that the traceback wasn't going into the log you were looking at made this harder to diagnose. I'll put in a PR to fix this, but I'm curious what is generating these deviceless alerts.

[lassej01]

Ok, i tried to update to 0.96.4. Before i started i commented out the VERA component in configuration.yaml and started. After that i enabled the vera component again and did a restart. Now the Vera component polls for sensors as it should. I saw one guy higher up in this thread that tried that and it worked for a while and then stopped, So we will see... but so far no exceptions from the vera component in the log. (Windows 10 platform, python 3.7)

[brandond]

@lielle1 can you re-pull that docker image and test? I've added additional guards against missing data.

[lielle1]

@brandond the image is looking good, everything works and no exception occurred so far.

[MarkJenniskens]

Having the same issue on 0.96.5 (hassio on VM on Synology NAS + vera lite)

[brandond]

I'm waiting on https://github.com/pavoni/pyvera/pull/113 to be accepted and pushed to PyPi so that I can reopen my hass PR. Anyone using Docker is welcome to use docker.io/brandond/home-assistant:pyvera-debug in the mean time.

[lielle1]

Is the HA DEV updated with the fix?

[MarkJenniskens]

Thanks for your efforts @brandond and @pavoni
Sadly 0.97.2 (with pyvera 0.3.3) does not resolve the issue. Could someone reopen?

Status changes of z-wave devices do not translate to HA states. (manual operation or via Vera interface).

Polling and subscribing works. No errors. Did some debugging and I can see pyvera receives the data from the vera API. But then the event is not fired...

[surfarn]

I also still have the same problem, running 0.97.0.

Please investigate!

mån 12 aug. 2019 kl. 11:26 skrev MarkJ [e-mail]:

Thanks for your efforts @brandond https://github.com/brandond and
@pavoni https://github.com/pavoni
Sadly 0.97.2 (with pyvera 0.3.3) does not resolve the issue. Could someone
reopen?

Status changes of z-wave devices do not translate to HA states. (manual
operation or via Vera interface).

Polling and subscribing works. No errors. Did some debugging and I can see
pyvera receives the data from the vera API. But then the event is not
fired...

—
You are receiving this because you commented.
Reply to this email directly, view it on GitHub
https://github.com/home-assistant/home-assistant/issues/24987?email_source=notifications&email_token=AMVIQVX3LKKEB6I35NYYV4DQEEUENA5CNFSM4H6TUOH2YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOD4B7XZQ#issuecomment-520354790,
or mute the thread
https://github.com/notifications/unsubscribe-auth/AMVIQVSQ6A4XQSC3UTRFOH3QEEUENANCNFSM4H6TUOHQ
.

[MarkJenniskens]

I found a fix!
this code on line 98 of subscribe.py:
device_list = self._devices.get(device_id, ())
to:
device_list = self._devices.get(int(device_id), ())

because device_id is a string and the keys in _self.devices are integers...
i'll put in a PR on pyvera.

[MarkJenniskens]

I also still have the same problem, running 0.97.0. Please investigate! mån 12 aug. 2019 kl. 11:26 skrev MarkJ [e-mail]:
…
Thanks for your efforts @brandond https://github.com/brandond and @pavoni https://github.com/pavoni Sadly 0.97.2 (with pyvera 0.3.3) does not resolve the issue. Could someone reopen? Status changes of z-wave devices do not translate to HA states. (manual operation or via Vera interface). Polling and subscribing works. No errors. Did some debugging and I can see pyvera receives the data from the vera API. But then the event is not fired... — You are receiving this because you commented. Reply to this email directly, view it on GitHub <#24987?email_source=notifications&email_token=AMVIQVX3LKKEB6I35NYYV4DQEEUENA5CNFSM4H6TUOH2YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOD4B7XZQ#issuecomment-520354790>, or mute the thread https://github.com/notifications/unsubscribe-auth/AMVIQVSQ6A4XQSC3UTRFOH3QEEUENANCNFSM4H6TUOHQ .

0.97.0 has pyvera 0.3.2.
Version 0.97.2 has pyvera 0.3.3.

[balloob]

Please open a new issue if the problem still happens.