8000 Platforms that do I/O inside properties · Issue #4210 · home-assistant/core · GitHub
[go: up one dir, main page]
More Web Proxy on the site http://driver.im/
Skip to content

Platforms that do I/O inside properties #4210

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
14 of 21 tasks
balloob opened this issue Nov 4, 2016 · 371 comments · Fixed by #4267 or #4268
Closed
14 of 21 tasks

Platforms that do I/O inside properties #4210

balloob opened this issue Nov 4, 2016 · 371 comments · Fixed by #4267 or #4268
Labels

Comments

@balloob
Copy link
Member
balloob commented Nov 4, 2016

If you came here because of a warning in your Home Assistant logs, please check if it is in the list below. If it is not, please add a reply with the brand of the product / platform and the time that it took to execute. Thanks

Platforms that have been reported as slow:

Reported but no suspicious behavior found:

  • sensor: template
  • sensor: date time
  • sensor: dark sky

Backstory

When we moved to async we started writing the state of entities to the state machine from within the event loop. This can only work correctly if no platforms or components do any I/O within any property of an entity. Instead, that work should be done inside the update method.

Bad

@property
def is_on(self):
    """Return if device is on."""
    return self._device.query_is_on()

Good

@property
def is_on(self):
    """Return if device is on."""
    return self._is_on

def update(self):
    """Update state of device."""
    self._is_on = self._device.query_is_on()

Although we cannot detect directly if I/O is happening inside a property, we can measure the time it takes us to fetch the properties. If this takes too long, it's probably bad and needs more research. In #4208 I implemented this warning which will redirect users to this issue.

@w1ll1am23
Copy link
Contributor
w1ll1am23 commented Nov 4, 2016

Fixed via #4219 Thanks @pvizeli
Component: Nest
Platform: Climate
Time to update (average of three): 0.474

Took a look at the python-nest platform and it is calling the nest API every X minutes it looks like (appears to be 5 minutes). So I am only seeing this issue logged once for every 5 updates.

The same code is used to update all Nest platforms so I assume this would be an issue with any of them.

@xehn
Copy link
xehn commented Nov 5, 2016

Reporting as requested.

I noticed this with the climate.radiotherm component. Delays vary between the two captures below. Hardware is a Radio Thermostat CT50. No idea if the time taken is being caused by the issue mentioned above, or just slow hardware. Functionality seems unaffected.

WARNING (MainThread) [homeassistant.helpers.entity] Updating state for climate.thermostat took 24.439 seconds. Please report platform to the developers at https://goo.gl/Nvioub
WARNING (MainThread) [homeassistant.helpers.entity] Updating state for climate.thermostat took 4.149 seconds. Please report platform to the developers at https://goo.gl/Nvioub

@bjw-s
Copy link
Contributor
bjw-s commented Nov 5, 2016

Seeing this behaviour as well with the media_player.sonos component, reporting as requested:

16-11-05 19:24:31 homeassistant.helpers.entity: Updating state for media_player.kitchen took 0.537 seconds. Please report platform to the developers at https://goo.gl/Nvioub

16-11-05 19:25:32 homeassistant.helpers.entity: Updating state for media_player.kitchen took 0.399 seconds. Please report platform to the developers at https://goo.gl/Nvioub

16-11-05 19:26:11 homeassistant.helpers.entity: Updating state for media_player.kitchen took 0.314 seconds. Please report platform to the developers at https://goo.gl/Nvioub

@dap35
Copy link
dap35 commented Nov 5, 2016

I am also seeing this with the media_player.sonos component on HA 0.32. I am also seeing the message below which is for the sonos controller package, not sure if it is at all related to this issue.. It does not appear to be updating the component.

Nov 05 14:57:44 rpi01.home.int hass[24265]: INFO:homeassistant.util.package:Attempting install of https://github.com/SoCo/SoCo/archive/cf8c2701165562eccbf1ecc879bf7060ceb0993e.zip#SoCo==0.12

@olines
Copy link
olines commented Nov 6, 2016

Here you go - reporting per log request:

16-11-06 03:28:16 homeassistant.helpers.entity: Updating state for cover.garagedoor took 1.176 seconds. Please report platform to the developers at https://goo.gl/Nvioub

16-11-06 03:28:32 homeassistant.helpers.entity: Updating state for cover.garagedoor took 1.428 seconds. Please report platform to the developers at https://goo.gl/Nvioub

16-11-06 03:28:46 homeassistant.helpers.entity: Updating state for cover.garagedoor took 1.167 seconds. Please report platform to the developers at https://goo.gl/Nvioub

@balloob
Copy link
Member Author
balloob commented Nov 6, 2016

Which platform is this?

On Sat, Nov 5, 2016, 20:56 olines notifications@github.com wrote:

Here you go - reporting per log request:

16-11-06 03:28:16 homeassistant.helpers.entity: Updating state for cover.garagedoor took 1.176 seconds. Please report platform to the developers at https://goo.gl/Nvioub

16-11-06 03:28:32 homeassistant.helpers.entity: Updating state for cover.garagedoor took 1.428 seconds. Please report platform to the developers at https://goo.gl/Nvioub

16-11-06 03:28:46 homeassistant.helpers.entity: Updating state for cover.garagedoor took 1.167 seconds. Please report platform to the developers at https://goo.gl/Nvioub


You are receiving this because you authored the thread.
Reply to this email directly, view it on GitHub
#4210 (comment),
or mute the thread
https://github.com/notifications/unsubscribe-auth/ABYJ2iIevk0Q3KCaVdLtK6aQUULeWWMLks5q7U_TgaJpZM4KpMod
.

@raccettura
Copy link
Contributor

I'm getting
16-11-06 01:29:01 homeassistant.helpers.entity: Updating state for climate.bedroom took 0.371 seconds. Please report platform to the developers at https://goo.gl/Nvioub

when connecting to my Honeywell thermostat API.

@frelev
Copy link
frelev commented Nov 6, 2016

I´m getting
homeassistant.helpers.entity: Updating state for switch.kitchen_lamp took 0.563 seconds. Please report platform to the developers at https://goo.gl/Nvioub

When trying to turn on a lamp using emulated hue

(lamp didn't turn on but I think there is an issue with emulated hue in latest version)

@balloob
Copy link
Member Author
balloob commented Nov 6, 2016

@frelev what platform is the lamp?

@TeeSeePeeEyePea
Copy link

I am getting the warning on cover.garage_door - it is the "myq" platform, from: http://pastebin.com/qVszax1t

@balloob
Copy link
Member Author
balloob commented Nov 6, 2016

@TeeSeePeeEyePea that component is indeed wrong. However, it is not part of Home Assistant so you'll have to find the author and have him fix it (the get_status call should be moved to a new update method) like done here: https://github.com/home-assistant/home-assistant/pull/4244/files

@frelev
Copy link
frelev commented Nov 6, 2016

@balloob It´s a tellstick (not Net) switch

@resoai
Copy link
resoai commented Nov 6, 2016

I have a huge number of KNX switches and I'm getting following in the error log (truncated):

16-11-06 20:54:28 homeassistant.helpers.entity: Updating state for switch.master_bedroom_spotlights took 1.022 seconds. Please report platform to the developers at https://goo.gl/Nvioub
16-11-06 20:54:29 homeassistant.helpers.entity: Updating state for switch.bathroom_shower_spotlights took 1.002 seconds. Please report platform to the developers at https://goo.gl/Nvioub
16-11-06 20:54:30 homeassistant.helpers.entity: Updating state for switch.toilet_extractor_fan took 1.002 seconds. Please report platform to the developers at https://goo.gl/Nvioub
16-11-06 20:54:31 homeassistant.helpers.entity: Updating state for switch.toilet_spotlight took 1.002 seconds. Please report platform to the developers at https://goo.gl/Nvioub
16-11-06 20:54:32 homeassistant.helpers.entity: Updating state for switch.bathroom_spotlights took 1.002 seconds. Please report platform to the developers at https://goo.gl/Nvioub
16-11-06 20:54:33 homeassistant.helpers.entity: Updating state for switch.hallway_ff_wall_lights took 1.003 seconds. Please report platform to the developers at https://goo.gl/Nvioub
16-11-06 20:54:34 homeassistant.helpers.entity: Updating state for switch.kitchen_centre_pendant took 1.003 seconds. Please report platform to the developers at https://goo.gl/Nvioub
16-11-06 20:54:35 homeassistant.helpers.entity: Updating state for switch.rear_gate took 1.003 seconds. Please report platform to the developers at https://goo.gl/Nvioub
16-11-06 20:54:36 homeassistant.helpers.entity: Updating state for switch.master_bedroom_wardrobe_spotlights took 1.002 seconds. Please report platform to the developers at https://goo.gl/Nvioub
16-11-06 20:54:37 homeassistant.helpers.entity: Updating state for switch.external_porch_wall_light took 1.003 seconds. Please report platform to the developers at https://goo.gl/Nvioub
16-11-06 20:54:38 homeassistant.helpers.entity: Updating state for switch.external_side_wall_lights took 1.003 seconds. Please report platform to the developers at https://goo.gl/Nvioub
16-11-06 20:54:39 homeassistant.helpers.entity: Updating state for switch.av_room_exctractor_fan took 1.003 seconds. Please report platform to the developers at https://goo.gl/Nvioub
16-11-06 20:54:40 homeassistant.helpers.entity: Updating state for switch.bathroom_extractor_fan took 1.003 seconds. Please report platform to the developers at https://goo.gl/Nvioub

@kylerw
Copy link
kylerw commented Nov 7, 2016

@TeeSeePeeEyePea I made submitted a pull request for https://github.com/arraylabs/myq that updates to handle multipe doors (using name from the app) as well as resolving the error here. Have a look (may need to check my fork) and let me know if you see any problems.

@MichaelMuir
Copy link

I am seeing lots of errors for pyW215 when I am using the D-Link DSP-W215 Switch, here is one example:

16-11-07 20:27:29 homeassistant.helpers.entity: Updating state for switch.patio_audio took 1.037 seconds. Please report platform to the developers at https://goo.gl/Nvioub

@tim-devel
Copy link

I am getting the warning message on the dark sky weather platform

@bestlibre
Copy link
Contributor

I'm also getting this warning for the new openweathermap component (weather platform)

homeassistant.helpers.entity: Updating state for weather.openweathermap took 0.241 seconds. Please report platform to the developers at https://goo.gl/Nvioub

This was referenced Nov 7, 2016
@tim-devel
Copy link
tim-devel commented Nov 7, 2016

I just got the message on a template sensor too:

Nov 7 20:19:01 pi2 hass[524]: WARNING:homeassistant.helpers.entity:Updating state for sensor.back_room_temp_update_timer took 0.547 seconds. Please report platform to the developers at https://goo.gl/Nvioub

- platform: template
   sensors:
     back_room_temp_update_timer:
       value_template: '{% if is_state("input_boolean.boot_delay", "off") %} {{ (as_timestamp(now()) - as_timestamp(states.sensor.back_room.last_updated)) / 60 }} {% else %} {{ 0 | int }} {% endif %}'
       entity_id: sensor.time
       unit_of_measurement: 'minutes'

@lwis
Copy link
Member
lwis commented Nov 7, 2016

@bestlibre could you try against #4298 ?
@MichaelMuir could you try against #4301 ?

@bdraco
Copy link
Member
bdraco commented Feb 3, 2020

Got a warning about Nut but it actually looks fine.

@jackkitley
Copy link

Running Hass 0.104.3
Updating state for media_player.samsung_tv_remote_2 (<class 'custom_components.samsungtv_custom.media_player.SamsungTVDeviceQLED'>) took 9.817 seconds.

@friendodevil
Copy link

Running Hass 0.105.2 | HassOS 3.8
Updating state for camera.aarlo_camera2 (<class 'custom_components.aarlo.camera.ArloCam'>) took 0.687 seconds.

@guice
Copy link
guice commented Feb 10, 2020

Came from custom component DreamScreen:

Updating state for dreamscreen.dream_screen (<class 'custom_components.dreamscreen.DreamScreenEntity'>) took 0.839 seconds.

HA Core: 0.105.2

@cabletie
Copy link
cabletie commented Feb 14, 2020

I'm getting the warning from the custom meross component :

2020-02-14 21:33:02 WARNING (MainThread) [homeassistant.helpers.entity] Updating state for switch.power_2_e805 (<class 'custom_compo
nents.meross_cloud.switch.SwitchEntityWrapper'>) took 0.545 seconds. Please report platform to the developers at https://goo.gl/Nvio
ub
2020-02-14 21:33:03 WARNING (MainThread) [homeassistant.helpers.entity] Updating state for switch.power_5_e043 (<class 'custom_compo
nents.meross_cloud.switch.SwitchEntityWrapper'>) took 0.684 seconds. Please report platform to the developers at https://goo.gl/Nvio
ub
2020-02-14 21:33:04 WARNING (MainThread) [homeassistant.helpers.entity] Updating state for switch.power_1 (<class 'custom_components
.meross_cloud.switch.SwitchEntityWrapper'>) took 0.550 seconds. Please report platform to the developers at https://goo.gl/Nvioub
2020-02-14 21:33:04 WARNING (MainThread) [homeassistant.helpers.entity] Updating state for switch.power_4_e039 (<class 'custom_components.meross_cloud.switch.SwitchEntityWrapper'>) took 0.688 seconds. Please report platform to the developers at https://goo.gl/Nvioub
2020-02-14 21:33:05 WARNING (MainThread) [homeassistant.helpers.entity] Updating state for switch.power_3_e29d (<class 'custom_components.meross_cloud.switch.SwitchEntityWrapper'>) took 0.709 seconds. Please report platform to the developers at https://goo.gl/Nvioub
2020-02-14 21:33:06 WARNING (MainThread) [homeassistant.helpers.entity] Updating state for switch.power_6_e2f7 (<class 'custom_components.meross_cloud.switch.SwitchEntityWrapper'>) took 0.944 seconds. Please report platform to the developers at https://goo.gl/Nvioub

Additionally and maybe related I get this traceback in the meross stuff:

2020-02-15 02:14:06 ERROR (MainThread) [homeassistant.helpers.entity] Update for sensor.power_6_e2f7 fails
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 279, in async_update_ha_state
    await self.async_device_update()
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 459, in async_device_update
    await self.async_update()
  File "/config/custom_components/meross_cloud/sensor.py", line 42, in async_update
    sensor_info = self._device.get_electricity()
  File "/usr/local/lib/python3.7/site-packages/meross_iot/cloud/devices/power_plugs.py", line 144, in get_electricity
    return self._get_electricity()['electricity']
  File "/usr/local/lib/python3.7/site-packages/meross_iot/cloud/devices/power_plugs.py", line 21, in _get_electricity
    return self.execute_command("GET", ELECTRICITY, {})
  File "/usr/local/lib/python3.7/site-packages/meross_iot/cloud/device.py", line 126, in execute_command
    return self.__cloud_client.execute_cmd(self.uuid, command, namespace, payload, callback=callback, timeout=timeout)
  File "/usr/local/lib/python3.7/site-packages/meross_iot/cloud/client.py", line 302, in execute_cmd
    raise CommandTimeoutException("A timeout occurred while waiting for the ACK: %d" % timeout)
meross_iot.cloud.exceptions.CommandTimeoutException.CommandTimeoutException: A timeout occurred while waiting for the ACK: 10
$ ha core info
arch: amd64
boot: true
custom: false
image: homeassistant/intel-nuc-homeassistant
ip_address: 172.30.32.1
last_version: 0.105.3
machine: intel-nuc
port: 8123
ssl: true
version: 0.105.2
wait_boot: 600
watchdog: true

HTH

@balloob
Copy link
Member Author
balloob commented Feb 14, 2020

@cabletie that's a problem with the custom component. It's doing I/O inside async_update. Please report it to the author of the custom component.

@twsl
Copy link
twsl commented Feb 17, 2020

Updating state for media_player.samsung_tv (<class 'custom_components.samsungtv_custom.media_player.SamsungTVDevice'>) took 0.976 seconds. Please report platform to the developers at https://goo.gl/Nvioub

@grahamr
Copy link
grahamr commented Feb 18, 2020

Component: Envisalink
Issue: Update State for Binary Sensor
Time: 0.704 seconds

Log:
2020-02-18 13:22:52 WARNING (MainThread) [homeassistant.helpers.entity] Updating state for binary_sensor.mud_room_door (<class 'homeassistant.components.envisalink.binary_sensor.EnvisalinkBinarySensor'>) took 0.704 seconds.

@EelcoAV
Copy link
EelcoAV commented Feb 18, 2020

Component: DSMR Sensor (Dutch smart electrical/gass smart meter):
Updating state for sensor.power_consumption_normal (<class 'homeassistant.components.dsmr.sensor.DSMREntity'>) took 0.531 seconds.
This message first showed up after updating to 0.105.5

@anonim-no
Copy link

Updating state for remote.kitchen_remote (<class 'homeassistant.components.xiaomi_miio.remote.XiaomiMiioRemote'>) took 0.415 seconds. Please report platform to the developers at https://goo.gl/Nvioub

@toddsantoro
Copy link

2020-02-21 11:50:58 WARNING (MainThread) [homeassistant.helpers.entity] Updating state for zone.laid_back_key_west (<class 'homeassistant.components.zone.Zone'>) took 1.989 seconds. Please report platform to the developers at https://goo.gl/Nvioub

@iluhis
Copy link
iluhis commented Feb 21, 2020

Updating state for remote.xiaomi_miio_192_168_1_113 (<class 'homeassistant.components.xiaomi_miio.remote.XiaomiMiioRemote'>) took 0.767 seconds. Please report platform to the developers at https://goo.gl/Nvioub

RasPi4 with Hassio installed from the Hass site

@JakeTheSnake
Copy link

Component: VerisureThermometer
Platform: Sensor
Time to update: 0.567 s

Updating state for sensor.garage_temperature (<class 'homeassistant.components.verisure.sensor.VerisureThermometer'>) took 0.567 seconds. Please report platform to the developers at https://goo.gl/Nvioub

Raspberry Pi 3B, docker

@jcassee
Copy link
jcassee commented Feb 23, 2020

2020-02-23 22:21:30 WARNING (MainThread) [homeassistant.helpers.entity] Updating state for sensor.voltage_sags_phase_l3 (<class 'homeassistant.components.dsmr.sensor.DSMREntity'>) took 2.699 seconds. Please report platform to the developers at https://goo.gl/Nvioub

@hbylow
Copy link
hbylow commented Feb 25, 2020

2020-02-25 20:40:59 WARNING (MainThread) [homeassistant.helpers.entity] Updating state for camera.ytterdorr (<class 'homeassistant.components.arlo.camera.ArloCam'>) took 23.405 seconds. Please report platform to the developers at https://goo.gl/Nvioub

@root-hal9000
Copy link

got one for mobile app running on a Moto G7:

Updating state for device_tracker.xxx_phone (<class 'homeassistant.components.mobile_app.device_tracker.MobileAppEntity'>) took 0.984 seconds. Please report platform to the developers at https://goo.gl/Nvioub

@Cobertizo
Copy link

As requested - one for the bom weather sensor:
“Updating state for weather.bom_home (<class 'homeassistant.components.bom.weather.BOMWeather'>) took 0.527 seconds. Please report platform to the developers at https://goo.gl/Nvioub”

@dcmartin
Copy link

2020-03-11 23:13:43 WARNING (MainThread) [homeassistant.helpers.entity] Updating state for sensor.motion_detected_entity_ago_bathroom_stdev_statistics (<class 'homeassistant.components.statistics.sensor.StatisticsSensor'>) took 0.887 seconds. Please report platform to the developers at https://goo.gl/Nvioub
2020-03-11 23:23:24 WARNING (MainThread) [homeassistant.helpers.entity] Updating state for binary_sensor.motion_annotated_bathroom (<class 'homeassistant.components.template.binary_sensor.BinarySensorTemplate'>) took 0.456 seconds. Please report platform to the developers at https://goo.gl/Nvioub

@S-Przybylski
Copy link

Since 0.109.0.dev i got a message related to the synology camera integration (Currently run 0.109.0.dev20200419):
2020-04-19 13:44:15 WARNING (MainThread) [homeassistant.util.async_] Detected I/O inside the event loop. This is causing stability issues. Please report issue for synology doing I/O at homeassistant/components/synology/camera.py, line 53: timeout=timeout,
2020-04-19 13:44:17 WARNING (MainThread) [homeassistant.util.async_] Detected I/O inside the event loop. This is causing stability issues. Please report issue for synology doing I/O at homeassistant/components/synology/camera.py, line 53: timeout=timeout,
2020-04-19 13:44:18 WARNING (MainThread) [homeassistant.util.async_] Detected I/O inside the event loop. This is causing stability issues. Please report issue for synology doing I/O at homeassistant/components/synology/camera.py, line 53: timeout=timeout,
2020-04-19 13:44:19 WARNING (MainThread) [homeassistant.util.async_] Detected I/O inside the event loop. This is causing stability issues. Please report issue for synology doing I/O at homeassistant/components/synology/camera.py, line 53: timeout=timeout,
2020-04-19 13:44:19 WARNING (MainThread) [homeassistant.util.async_] Detected I/O inside the event loop. This is causing stability issues. Please report issue for synology doing I/O at homeassistant/components/synology/camera.py, line 53: timeout=timeout,
2020-04-19 13:44:20 WARNING (MainThread) [homeassistant.util.async_] Detected I/O inside the event loop. This is causing stability issues. Please report issue for synology doing I/O at homeassistant/components/synology/camera.py, line 53: timeout=timeout,
2020-04-19 13:44:20 WARNING (MainThread) [homeassistant.util.async_] Detected I/O inside the event loop. This is causing stability issues. Please report issue for synology doing I/O at homeassistant/components/synology/camera.py, line 53: timeout=timeout,

@S-Przybylski
Copy link

Dear @balloob
The event loop message Synology camera module do not appear any longer! Semms to be fixed by that! Thanks!

@nhok3296
Copy link

Log Details (WARNING)
Version: 0.109.0b0
Logger: homeassistant.util.async_
Source: util/async_.py:120
First occurred: 7:29:41 (1 occurrences)
Last logged: 7:29:41
Detected I/O inside the event loop. This is causing stability issues. Please report issue to the custom component author for smartir doing I/O at custom_components/smartir/init.py, line 68: request = requests.get(MANIFEST_URL.format(branch), stream=True, timeout=10)

@balloob
Copy link
Member Author
balloob commented Apr 23, 2020

@nhok3296 please report this to the author of the custom component that you are using, as per the message.

@nhok3296
Copy link

Ok

@mcc05
Copy link
Contributor
mcc05 commented Jun 14, 2020

May I ask, when you have an inital update that may take some time to complete, what is the best way to do this? for example intial call to update function may take 10sec and after that <1 sec. Is there an override to stop the warnings, or another way?

@frenck
Copy link
Member
frenck commented Aug 11, 2020

This issue is overdue. A lot of fixes have been implemented or not tracked in here anymore.

The log message in Home Assistant has been adjusted a while back and now requests to create a separate issue (which we can assign to the specific integration or codeowner). This is more productive at this point compared to this issue.

So, if you run into an issue as described here, please open up a new, separate issue.

Thanks 👍

@frenck frenck closed this as completed Aug 11, 2020
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
0