search

legrego / homeassistant-elasticsearch

Publish Home-Assistant events to Elasticsearch
https://legrego.github.io/homeassistant-elasticsearch/
MIT License
145 stars 38 forks source link

Detected I/O inside the event loop #97

Closed kkellner closed 4 years ago

kkellner commented 4 years ago

Environment Home-Assistant version: 0.109.3 Elasticsearch version: 0.2.2

Describe the bug

I new warning was introduced in HASS 0.109 when I/O it performed within event loop. Getting the following warning:

WARNING (MainThread) [homeassistant.util.async_] Detected I/O inside the event loop. This is causing stability issues. Please report issue to the custom component author for elastic doing I/O at custom_components/elastic/__init__.py, line 512: bulk_response = bulk(self._gateway.get_client(), actions)

To Reproduce Steps to reproduce the behavior: Startup HASS and wait, the WARNING log messages will be produced.

kkellner commented 4 years ago

For reference: https://www.home-assistant.io/blog/2020/04/29/release-109/#detection-of-blocking-io-in-the-event-loop

legrego commented 4 years ago

Thanks for the heads-up, @kkellner. My HASS Install is woefully out of date right now, so I probably would have missed this warning for quite a while

JZ-SmartThings commented 4 years ago

Yep here's a full array of warnings so that you can see line numbers and method calls...

root@UBUNTU64:/etc/mysql# /hassutil -r |grep elastic Are you sure that you want to restart Home Assistant? [y/N] y May 11 14:41:44 UBUNTU64 hass[24835]: 2020-05-11 14:41:44 INFO (SyncWorker_0) [homeassistant.loader] Loaded elastic from custom_components.elastic May 11 14:41:44 UBUNTU64 hass[24835]: 2020-05-11 14:41:44 WARNING (MainThread) [homeassistant.loader] You are using a custom integration for elastic which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant. May 11 14:41:46 UBUNTU64 hass[24835]: 2020-05-11 14:41:46 INFO (MainThread) [homeassistant.setup] Setting up elastic May 11 14:41:46 UBUNTU64 hass[24835]: 2020-05-11 14:41:46 WARNING (MainThread) [homeassistant.util.async_] Detected I/O inside the event loop. This is causing stability issues. Please report issue to the custom component author for elastic doing I/O at custom_components/elastic/__init__.py, line 153: version = client.info()["version"] May 11 14:41:46 UBUNTU64 hass[24835]: 2020-05-11 14:41:46 INFO (MainThread) [elasticsearch] GET http://localhost:9200/ [status:200 request:0.034s] May 11 14:41:46 UBUNTU64 hass[24835]: 2020-05-11 14:41:46 WARNING (MainThread) [homeassistant.util.async_] Detected I/O inside the event loop. This is causing stability issues. Please report issue to the custom component author for elastic doing I/O at custom_components/elastic/__init__.py, line 282: if not client.indices.exists_template(name=INDEX_TEMPLATE_NAME): May 11 14:41:46 UBUNTU64 hass[24835]: 2020-05-11 14:41:46 INFO (MainThread) [elasticsearch] HEAD http://localhost:9200/_template/hass-index-template-v4_1 [status:200 request:0.025s] May 11 14:41:46 UBUNTU64 hass[24835]: 2020-05-11 14:41:46 WARNING (MainThread) [homeassistant.util.async_] Detected I/O inside the event loop. This is causing stability issues. Please report issue to the custom component author for elastic doing I/O at custom_components/elastic/__init__.py, line 319: if not client.indices.exists_alias(name=self.index_alias): May 11 14:41:46 UBUNTU64 hass[24835]: 2020-05-11 14:41:46 INFO (MainThread) [elasticsearch] HEAD http://localhost:9200/_alias/active-hass-index-v4_1 [status:200 request:0.007s] May 11 14:41:46 UBUNTU64 hass[24835]: 2020-05-11 14:41:46 WARNING (MainThread) [homeassistant.util.async_] Detected I/O inside the event loop. This is causing stability issues. Please report issue to the custom component author for elastic doing I/O at custom_components/elastic/__init__.py, line 335: client.indices.put_settings(index=self.index_alias, preserve_existing=True, body={ May 11 14:41:47 UBUNTU64 hass[24835]: 2020-05-11 14:41:47 INFO (MainThread) [elasticsearch] PUT http://localhost:9200/active-hass-index-v4_1/_settings?preserve_existing=true [status:200 request:0.524s] May 11 14:41:47 UBUNTU64 hass[24835]: 2020-05-11 14:41:47 WARNING (MainThread) [homeassistant.util.async_] Detected I/O inside the event loop. This is causing stability issues. Please report issue to the custom component author for elastic doing I/O at custom_components/elastic/__init__.py, line 359: existing_policy = client.transport.perform_request('GET', url) May 11 14:41:47 UBUNTU64 hass[24835]: 2020-05-11 14:41:47 INFO (MainThread) [elasticsearch] GET http://localhost:9200/_ilm/policy/home-assistant [status:200 request:0.009s] May 11 14:41:47 UBUNTU64 hass[24835]: 2020-05-11 14:41:47 INFO (MainThread) [custom_components.elastic] Updating existing ILM Policy 'home-assistant' May 11 14:41:47 UBUNTU64 hass[24835]: 2020-05-11 14:41:47 WARNING (MainThread) [homeassistant.util.async_] Detected I/O inside the event loop. This is causing stability issues. Please report issue to the custom component author for elastic doing I/O at custom_components/elastic/__init__.py, line 399: client.transport.perform_request('PUT', url, body=policy) May 11 14:41:47 UBUNTU64 hass[24835]: 2020-05-11 14:41:47 INFO (MainThread) [elasticsearch] PUT http://localhost:9200/_ilm/policy/home-assistant [status:200 request:0.178s] May 11 14:41:47 UBUNTU64 hass[24835]: 2020-05-11 14:41:47 INFO (MainThread) [custom_components.elastic] Elastic component fully initialized May 11 14:41:47 UBUNTU64 hass[24835]: 2020-05-11 14:41:47 INFO (MainThread) [homeassistant.setup] Setup of domain elastic took 0.9 seconds. May 11 14:41:47 UBUNTU64 hass[24835]: 2020-05-11 14:41:47 INFO (MainThread) [custom_components.elastic] Publishing 1 documents to Elasticsearch May 11 14:41:47 UBUNTU64 hass[24835]: 2020-05-11 14:41:47 WARNING (MainThread) [homeassistant.util.async_] Detected I/O inside the event loop. This is causing stability issues. Please report issue to the custom component author for elastic doing I/O at custom_components/elastic/__init__.py, line 512: bulk_response = bulk(self._gateway.get_client(), actions) May 11 14:41:47 UBUNTU64 hass[24835]: 2020-05-11 14:41:47 INFO (MainThread) [elasticsearch] POST http://localhost:9200/_bulk [status:200 request:0.027s] May 11 14:41:47 UBUNTU64 hass[24835]: 2020-05-11 14:41:47 INFO (MainThread) [custom_components.elastic] Publish Succeeded May 11 14:41:51 UBUNTU64 hass[24835]: 2020-05-11 14:41:51 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.elastic May 11 14:41:51 UBUNTU64 hass[24835]: 2020-05-11 14:41:51 INFO (SyncWorker_5) [custom_components.elastic.sensor] Initializing cluster health sensor May 11 14:41:51 UBUNTU64 hass[24835]: 2020-05-11 14:41:51 INFO (SyncWorker_5) [custom_components.elastic.sensor] Initializing publish queue sensor May 11 14:41:51 UBUNTU64 hass[24835]: 2020-05-11 14:41:51 INFO (SyncWorker_6) [elasticsearch] GET http://localhost:9200/_cluster/health [status:200 request:0.007s] May 11 14:42:17 UBUNTU64 hass[24835]: 2020-05-11 14:42:17 INFO (MainThread) [custom_components.elastic] Publishing 261 documents to Elasticsearch May 11 14:42:17 UBUNTU64 hass[24835]: 2020-05-11 14:42:17 WARNING (MainThread) [homeassistant.util.async_] Detected I/O inside the event loop. This is causing stability issues. Please report issue to the custom component author for elastic doing I/O at custom_components/elastic/__init__.py, line 512: bulk_response = bulk(self._gateway.get_client(), actions) May 11 14:42:18 UBUNTU64 hass[24835]: 2020-05-11 14:42:18 INFO (MainThread) [elasticsearch] POST http://localhost:9200/_bulk [status:200 request:0.574s] May 11 14:42:18 UBUNTU64 hass[24835]: 2020-05-11 14:42:18 INFO (MainThread) [custom_components.elastic] Publish Succeeded May 11 14:42:22 UBUNTU64 hass[24835]: 2020-05-11 14:42:22 INFO (SyncWorker_1) [elasticsearch] GET http://localhost:9200/_cluster/health [status:200 request:0.003s] May 11 14:42:48 UBUNTU64 hass[24835]: 2020-05-11 14:42:48 INFO (MainThread) [custom_components.elastic] Publishing 22 documents to Elasticsearch May 11 14:42:48 UBUNTU64 hass[24835]: 2020-05-11 14:42:48 WARNING (MainThread) [homeassistant.util.async_] Detected I/O inside the event loop. This is causing stability issues. Please report issue to the custom component author for elastic doing I/O at custom_components/elastic/__init__.py, line 512: bulk_response = bulk(self._gateway.get_client(), actions) May 11 14:42:48 UBUNTU64 hass[24835]: 2020-05-11 14:42:48 INFO (MainThread) [elasticsearch] POST http://localhost:9200/_bulk [status:200 request:0.030s] May 11 14:42:48 UBUNTU64 hass[24835]: 2020-05-11 14:42:48 INFO (MainThread) [custom_components.elastic] Publish Succeeded

eloebl commented 4 years ago

Just got it installed and ran into this as well with 0.110.1. Thank you for creating this :)

Detected I/O inside the event loop. This is causing stability issues. Please report issue to the custom component author for elastic doing I/O at custom_components/elastic/__init__.py, line 319: if not client.indices.exists_alias(name=self.index_alias):
Detected I/O inside the event loop. This is causing stability issues. Please report issue to the custom component author for elastic doing I/O at custom_components/elastic/__init__.py, line 337: "index.lifecycle.rollover_alias": self.index_alias
Detected I/O inside the event loop. This is causing stability issues. Please report issue to the custom component author for elastic doing I/O at custom_components/elastic/__init__.py, line 359: existing_policy = client.transport.perform_request('GET', url)
Detected I/O inside the event loop. This is causing stability issues. Please report issue to the custom component author for elastic doing I/O at custom_components/elastic/__init__.py, line 399: client.transport.perform_request('PUT', url, body=policy)
Detected I/O inside the event loop. This is causing stability issues. Please report issue to the custom component author for elastic doing I/O at custom_components/elastic/__init__.py, line 512: bulk_response = bulk(self._gateway.get_client(), actions)
legrego commented 4 years ago

Hey @kkellner, @JZ-SmartThings, @mloebl:

I have a beta release (v0.2.3-beta.1) which aims to resolve this. Everything seems to be working well in my own setup, but I would appreciate additional testers to make sure it's working as expected: https://github.com/legrego/homeassistant-elasticsearch/releases/tag/v0.2.3-beta.1

eloebl commented 4 years ago

So far, so good! Also can't tell if it's my imagination, but the general HA UI seems noticeable faster/more responsive after swapping this out. Thank you very much for this! I've also been using your Homeseer beat, but been moving towards HA, so this is great.

legrego commented 4 years ago

@mloebl thanks for the fast response! I'll give this a couple of days for others to test if they get a chance too.

I've also been using your Homeseer beat, but been moving towards HA, so this is great.

Well there's a surprise! I wrote that one day out of boredom, and haven't been maintaining it. I'm glad someone else found it useful 😄

eloebl commented 4 years ago

@legrego It works very well, took a bit for me to get the proper beats build environment running initially, but built it against 7.6.2 a few weeks back and has been stable with HS3 and now HS4 Beta. I stood up my first simple 2 node elastic cluster a couple months ago at my house, and I am loving it. Between being about to bring in the system logs, firewall/surciatanet/netflow logs, and now my HS/HA logs, it's a great single location to track what's going on with my home network. We're staging up another Elasticstack at work, and I suspect we'll be installing this on the HA system there as well.

JZ-SmartThings commented 4 years ago

@legrego it works very well. Still getting my state changes in ES and the HA log is clean. @mloebl I wish it made my HA faster :smile:

As a side note, every time I restart HA, it dumped every single state into ES and the bar chart looked super tall for my automation chart. This update stopped this behavior and now the HA restarts don't dump all states. Thanks again @legrego!!!

kkellner commented 4 years ago

v0.2.3-beta.1 -- So far so good

kkellner commented 4 years ago

I am still getting "field name cannot be an empty string" but that has nothing to do with this issue. It's a separate issue described here: https://github.com/legrego/homeassistant-elasticsearch/issues/96

legrego commented 4 years ago

I am still getting "field name cannot be an empty string" but that has nothing to do with this issue. It's a separate issue described here: https://github.com/legrego/homeassistant-elasticsearch/issues/96

Yeah that is expected. I have a fix ready in https://github.com/legrego/homeassistant-elasticsearch/pull/98 if you’re interested in verifying that too 🙂

legrego commented 4 years ago

Keep an eye out for a stable v0.2.3 release in the near future. I have a couple other items I want to address in this release, but feel free to run the beta in the meantime if you want to capture this specific fix.