home-assistant / core

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

Spurious warnings: "Update of Mi Temp sensor is taking over 10 seconds" data comes through fine #20557

Closed y0ast closed 5 years ago

y0ast commented 5 years ago

Home Assistant release with the issue: 0.86.2

Last working Home Assistant release (if known): unclear, happening since at least 0.84.0 when I got the device

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

Component/platform: https://www.home-assistant.io/components/sensor.mitemp_bt/

Description of problem: Home assistant log:

Update of sensor.round_sensor_humidity is taking over 10 seconds
11:26 PM util/async_.py (WARNING)

Update of sensor.round_sensor_temperature is taking over 10 seconds
11:11 PM util/async_.py (WARNING)

Message comes up every 15 min (which is the update interval). Temperature/humidity come through just fine, so actual update works. Sensor timeout is set to 30 seconds, but apparently not passed through to async_.py. I have placed the temperature sensor next to my pi, so it's not a distance issue.

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

sensor:
 - platform: mitemp_bt
   name: 'Round Sensor'
   mac: '[anonymised]'
   timeout: 30
   cache_value: 900
   monitored_conditions:
     - temperature
     - humidity

Traceback (if applicable): NA, data comes through

Additional information: This is not a major issue, the log is just spammed with spurious warnings while data comes through fine. Perhaps the solution is as simple as increasing the timeout value for async_.py for this sensor, however I find it hard to believe HA needs 10sec to update a BLE device.

awarecan commented 5 years ago

You should change your timeout value to 9 if you want to remove this specific warning message.

However, even you do so, the warning might be still exist since the timeout in the config didn't passed to upstream lib (hardcoded to 10 seconds).

See: https://github.com/ratcashdev/mitemp/blob/bd6ffed5bfd9a3a52dd8a4b96e896fa79b5c5f10/mitemp_bt/mitemp_bt_poller.py#L68

y0ast commented 5 years ago

@awarecan Thanks for the pointer, I have made a PR to fix the hardcoding upstream: https://github.com/ratcashdev/mitemp/pull/7

I do wonder if this will fix the issue, since the warning comes from async_.py I have a feeling this is a "default warning" that is thrown for any sensor after 10 sec. Is that correct? I also wonder why your suggestion of setting it to 9 seconds would help.

Sometimes even the 30 sec timeout is hit and then I see a warning from coming from the sensor file directly.

awarecan commented 5 years ago

Yes, your understand is correct. The 10 second warning threshold is "default settings", that is why I said if you set timeout to 9 seconds, you will not see this warning again. But you may get more timeout exception.

y0ast commented 5 years ago

I've found that always one of the two entities (temperature or humidity) gives a warning, but never both at the same time:

2019-01-29 17:01:11 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.round_sensor_temperature is taking over 10 seconds
2019-01-29 17:16:41 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.round_sensor_humidity is taking over 10 seconds
2019-01-29 17:32:10 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.round_sensor_humidity is taking over 10 seconds
2019-01-29 17:47:40 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.round_sensor_temperature is taking over 10 seconds
2019-01-29 18:03:10 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.round_sensor_humidity is taking over 10 seconds
2019-01-29 18:18:40 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.round_sensor_temperature is taking over 10 seconds
2019-01-29 18:34:10 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.round_sensor_humidity is taking over 10 seconds
2019-01-29 18:49:40 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.round_sensor_humidity is taking over 10 seconds
2019-01-29 19:05:10 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.round_sensor_humidity is taking over 10 seconds
2019-01-29 19:20:40 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.round_sensor_temperature is taking over 10 seconds

Could it be that HA tries to kick off both, but one keeps a lock on the BT backend for long enough for the other not to finish in time?

I believe they're added to the entities list here: https://github.com/home-assistant/home-assistant/blob/1be440a72b79c96d633ed796b16f802e6aa0a1f2/homeassistant/components/sensor/mitemp_bt.py#L90

Is it possible to add a delay between them? Would it make sense for me to define the two entities as different platforms with each just 1 monitored condition?

jladefoged commented 5 years ago

I get the same warning. The HA log is flooded with warnings from homeassistant.helpers.entity and homeassistant.components.sensor

y0ast commented 5 years ago

More here also: https://community.home-assistant.io/t/xiaomi-mijia-bluetooth-temperature-humidity-sensor-compatibility/43568/22

I've not gotten any further with this. I tried removing the humidity/battery reading and kept only temperature but the warnings still show up. I currently think it's an issue with the BT hardware just taking a very long time to start, take a reading and return the result.

It's not easy to pinpoint it to that cause though.

Let me know if you find something. It's a bit of an annoying issue since it makes the log useless.

jladefoged commented 5 years ago

I've tested with 4 different bluetooth dongles with the same result. I'm currently using a LM1010 (great class 1 dongle with external antenna).

stale[bot] commented 5 years ago

There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates. Please make sure to update to the latest Home Assistant version and check if that solves the issue. Let us know if that works for you by adding a comment 👍 This issue now has been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.

poudenes commented 5 years ago

Hello All,

I have same issue. Also with latest HA version 0.100.2:


2019-10-18 09:14:21 WARNING (MainThread) [homeassistant.setup] Setup of group is taking over 10 seconds.
2019-10-18 09:14:21 WARNING (MainThread) [homeassistant.setup] Setup of person is taking over 10 seconds.
2019-10-18 09:14:22 WARNING (MainThread) [homeassistant.setup] Setup of input_boolean is taking over 10 seconds.
2019-10-18 09:14:40 WARNING (MainThread) [homeassistant.components.weather] Setup of platform darksky is taking over 10 seconds.
2019-10-18 09:14:44 WARNING (MainThread) [homeassistant.components.binary_sensor] Setup of platform ping is taking over 10 seconds.
2019-10-18 09:14:44 WARNING (MainThread) [homeassistant.components.calendar] Setup of platform caldav is taking over 10 seconds.
2019-10-18 09:14:44 WARNING (MainThread) [homeassistant.setup] Setup of cloud is taking over 10 seconds.
2019-10-18 09:14:44 WARNING (MainThread) [homeassistant.components.climate] Setup of platform nest is taking over 10 seconds.
2019-10-18 09:14:44 WARNING (MainThread) [homeassistant.setup] Setup of zeroconf is taking over 10 seconds.
2019-10-18 09:14:44 WARNING (MainThread) [homeassistant.components.media_player] Setup of platform kodi is taking over 10 seconds.
2019-10-18 09:14:44 WARNING (MainThread) [homeassistant.setup] Setup of script is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.switch] Setup of platform mqtt is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.light] Setup of platform mqtt is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.light] Setup of platform nanoleaf is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.remote] Setup of platform harmony is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.weather] Setup of platform met is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.device_tracker] Setup of platform geofency is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.switch] Setup of platform mqtt is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.light] Setup of platform mqtt is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.light] Setup of platform nanoleaf is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.remote] Setup of platform harmony is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.weather] Setup of platform met is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.device_tracker] Setup of platform geofency is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.setup] Setup of hassio is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.media_player] Setup of platform apple_tv_mrp is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform template is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform snmp is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform template is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform snmp is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform template is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform snmp is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform template is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform snmp is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform template is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform snmp is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform template is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform snmp is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform dsmr is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform systemmonitor is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform buienradar is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform command_line is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform version is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform command_line is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform version is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform time_date is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform mqtt is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform rdw is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform mqtt is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform rest is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform mqtt is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform rest is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform mqtt is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform rest is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform mqtt is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform rest is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform mqtt is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform rest is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform mqtt is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform rest is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform mqtt is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform rest is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform mqtt is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform mqtt is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform mqtt is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform mqtt is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform airvisual is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform mqtt is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform template is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform mqtt is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform template is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform darksky is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform template is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform snmp is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform template is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform snmp is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform template is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform snmp is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.components.sensor] Setup of platform template is taking over 10 seconds.
2019-10-18 09:15:00 WARNING (MainThread) [homeassistant.setup] Setup of default_config is taking over 10 seconds.```