gurumitts / pylutron-caseta

Apache License 2.0
154 stars 97 forks source link

latency for occupancy sensors? #66

Open gmcmicken opened 3 years ago

gmcmicken commented 3 years ago

Hi, I'm trying to diagnose an issue where the occupancy sensor update in HA is 0-3 seconds delayed. I logged the trigger time and action time in HA and found only .03 second delay so my next thought is that the update from the smart bridge might be delayed or picked up late, is there some logging I can do to diagnose this?

Reading the docs on HA website I was under the impression this should be almost instantaneous.

swails commented 3 years ago

What automation are you trying to use it in? I added the original implementation of occ sensor subscription, and while doing that work I found that pylutron_caseta received occupancy events effectively instantaneously. This is expected, since pylutron_caseta makes a local connection and Caseta latency from devices to the smart bridge is exceptionally good.

I did, however, have issues with latency when using occupancy sensors in complex automations with conditional steps. The logs from pylutron_caseta still indicated that the message was received nearly instantaneously, so I'm pretty convinced that the latency came from everything home assistant had to do to process it.

There were some things I did to streamline and simplify the automation that improved latency and the lighting experience both for Caseta and Home Assistant (created scenes to trigger in Caseta instead of having Home Assistant set light levels for the two lights individually, use sun elevation instead of sunset/sunrise, and reduced the size of the conditionals), but it's still taking around 0.5 - 1 second. But I think the latency hit ultimately comes from HA picking up the automation on the event loop, doing template evaluations, and then triggering the events. I don't see anything pylutron_caseta can do to improve latency for occ sensors.

Can you share the automation (YAML) with the unacceptable latency? I may be able to offer some suggestions for reducing latency.

gmcmicken commented 3 years ago

Thanks, I found a thread a few days ago about HA automation performance issues, something about the database writes but now I've lost it!

I am testing with just a single automation at the moment writing to the logs:

description: ''
trigger:
  - platform: state
    entity_id: binary_sensor.stairs_occupancy
    to: 'on'
condition: []
action:
  - service: system_log.write
    data_template:
      message: 'trigger time: {{trigger.to_state.last_updated}} run time: {{ now() }}'
      level: warning
mode: single

What I need to do is timestamp the moment pylutron_caseta receives the new state. Can I set debug on this to test?

mdonoughe commented 3 years ago

If you configure the Home Assistant logging to output debug messages from pylutron_caseta.leap you should see all the messages as they are received.

swails commented 3 years ago

You can also use the recorder component to dump all events (including occupancy state changes) to a SQL database. I'm currently dumping all of these lighting and occupancy events (along with sensor data like temperature, humidity, solar power generation, power usage from smart outlets with power monitoring, etc.) into an influx database and PostgreSQL database to feed analyses and dashboards (via grafana).

In addition to turning on lutron_caseta logging as @mdonoughe recommended, this should give you plenty to investigate with.

gmcmicken commented 3 years ago

@mdonoughe Okay I did debugging on lutron_caseta and that didn't really show me anything, so I'll do "pylutron_caseta.leap" and see where that gets me...

@swails Thanks, I think though I have good idea of the time in which the occupancy state is being recorded in HA so I need to work backward to when it is being delivered, unless you think "trigger.to_state.last_updated" would not show me the true time in which it was received?