OpenTherm/config: blocking call to sleep inside the event loop

[andriej]

The problem

I have issue with OpenTherm (OTGW) integration. It uses socket:// to connect to gateway and I see warning in logfile:

2024-05-16 15:30:33.962 WARNING (MainThread) [homeassistant.util.loop] Detected blocking call to sleep inside the event loop by integration 'config' at homeassistant/components/config/config_entries.py, line 120: await hass.config_entries.async_reload(entry_id) (offender: /usr/local/lib/python3.12/site-packages/serial/urlhandler/protocol_socket.py, line 104: time.sleep(0.3)), please create a bug report at https://github.com/home-assistant/core/issues?q=is%3Aopen+is%3Aissue+label%3A%22integration%3A+config%22

I do not see any other errors regarding OpenTherm. Only informational that it can't connect to socket:// in UI (when I hover on the error, I see `Could not connect to gateway at socket://ip:port <Errno 111>)

It was working all releases before 2024.5.

What version of Home Assistant Core has the issue?

core-2024.5.3

What was the last working version of Home Assistant Core?

core-2024.4.4

What type of installation are you running?

Home Assistant OS

Integration causing the issue

OpenTherm Gateway

Link to integration documentation on our website

https://www.home-assistant.io/integrations/opentherm_gw/

Diagnostics information

No response

Example YAML snippet

No response

Anything in the logs that might be useful for us?

Turning debug and reloading integration doesn't provide much info, as it seems it's issue with config/HA interpretation of 'socket://' connection? 2024-05-17 01:16:38.208 DEBUG (MainThread) [pyotgw.status] Starting reporting routine 2024-05-17 01:16:38.225 WARNING (MainThread) [homeassistant.util.loop] Detected blocking call to sleep inside the event loop by integration 'config' at homeassistant/components/config/config_entries.py, line 120: await hass.config_entries.async_reload(entry_id) (offender: /usr/local/lib/python3.12/site-packages/serial/urlhandler/protocol_socket.py, line 104: time.sleep(0.3)), please create a bug report at https://github.com/home-assistant/core/issues?q=is%3Aopen+is%3Aissue+label%3A%22integration%3A+config%22

Additional information

Could be connected with https://github.com/home-assistant/core/pull/116635

[home-assistant[bot]]

Hey there @mvn23, mind taking a look at this issue as it has been labeled with an integration (opentherm_gw) you are listed as a code owner for? Thanks!

Code owner commands

Code owners of `opentherm_gw` can trigger bot actions by commenting: - `@home-assistant close` Closes the issue. - `@home-assistant rename Awesome new title` Renames the issue. - `@home-assistant reopen` Reopen the issue. - `@home-assistant unassign opentherm_gw` Removes the current integration label and assignees on the issue, add the integration domain after the command. - `@home-assistant add-label needs-more-information` Add a label (needs-more-information, problem in dependency, problem in custom component) to the issue. - `@home-assistant remove-label needs-more-information` Remove a label (needs-more-information, problem in dependency, problem in custom component) on the issue.

_{^{(message by CodeOwnersMention)}}

---

opentherm_gw documentation opentherm_gw source _{^{(message by IssueLinks)}}

[mvn23]

Thank you for the report. Unfortunately I have not been able to reproduce the issue so far. We had a similar issue in the past (see #67430 for example) but it was supposed to be fixed with the change to pyserial-asyncio-fast in #116527 When does the message show up in the logs? Do you have a reliable way to reproduce the issue? The log message hints on an integration reload, but that doesn't trigger any errors for me...

[andriej]

Any hints on how can I reproduce? Everytime I restarts HA it ends up the same - integration says it can't connect. Connection is there as direct connection with client shows the data messages flowing.

[mvn23]

What do you mean by "direct connection with client"? If there is a successful connection from Home Assistant to the gateway then the debug logging should show all messages as well. If they don't show then there is no data being received by Home Assistant.

For the reproduction, do I understand correctly that the log message shows up on a restart of Home Assistant? Can you trigger it by reloading the integration? Or by disconnecting the gateway after the connection has been established? If we can find a way to reliably trigger the error then it will be easier to debug and fix.

[andriej]

HA cannot make successful connection even once.

I am testing connection on putty to make sure it's not OTGW gateway fault.

I've turned on "debug" on OpenTherm integration but messages I pasted are the only ones I have in my log file

Restart of OS or HA does not solve the situation, HA still can't connect to OTGW even once (so no debug messages in logfile). How can I further help it debug?

I guess problem is with how HA interprets "socket://" in URI to the OTGW and that's the issue, but I'm not sure on this - I just interpret the error.

[mvn23]

If you have the Terminal & SSH addon you can use nc <ip> <port> (that's separated by spaces) to test basic connectivity. If the messages don't show up there then it's likely a networking issue. It's still not great that the blocking call message shows up and I'll keep looking for the issue there, but it may help you find out why the integration is not working.

[andriej]

nc works from my machine and from HA OS too: ➜ ~ nc 192.168.x.x 2222 T00110000 BC0110000 T80190000 BC0192C00 T00090000 BC0090000 T00630000 BC0630000 ^Cpunt!

➜ ~

[andriej]

If it changes anything - updating to 2024.5.4 ddin't solve the problem.

[mvn23]

Only informational that it can't connect to socket:// in UI (when I hover on the error, I see `Could not connect to gateway at socket://ip:port <Errno 111>)

Error 111 means 'Connection Refused'. Since you seem to be able to connect with nc I don't see why this would happen. Can you post a debug log from start until this message and the 'blocking call' message have both shown up? If there's anything related to opentherm_gw or pyotgw shortly after that then please include that as well.

[andriej]

Unfortunately I do not have more debug logs, as it seems that OTGW is not even "used" in this connection. Integration is loaded but not throwing errors in logs because there's Errno 111, which is irrelevant as I can access the data directly and have been restarting the gateway multiple times.

[andriej]

In latest version of HA, the log while trying to reload OTGW integration is much more detailed:

Detected blocking call to sleep inside the event loop by integration 'config' at homeassistant/components/config/config_entries.py, line 120: await hass.config_entries.async_reload(entry_id) (offender: /usr/local/lib/python3.12/site-packages/serial/urlhandler/protocol_socket.py, line 104: time.sleep(0.3)), please create a bug report at https://github.com/home-assistant/core/issues?q=is%3Aopen+is%3Aissue+label%3A%22integration%3A+config%22 Traceback (most recent call last): File "", line 198, in _run_module_as_main File "", line 88, in _run_code File "/usr/src/homeassistant/homeassistant/main.py", line 223, in sys.exit(main()) File "/usr/src/homeassistant/homeassistant/main.py", line 209, in main exit_code = runner.run(runtime_conf) File "/usr/src/homeassistant/homeassistant/runner.py", line 190, in run return loop.run_until_complete(setup_and_run_hass(runtime_config)) File "/usr/local/lib/python3.12/asyncio/base_events.py", line 672, in run_until_complete self.run_forever() File "/usr/local/lib/python3.12/asyncio/base_events.py", line 639, in run_forever self._run_once() File "/usr/local/lib/python3.12/asyncio/base_events.py", line 1988, in _run_once handle._run() File "/usr/local/lib/python3.12/asyncio/events.py", line 88, in _run self._context.run(self._callback, *self._args) File "/usr/local/lib/python3.12/site-packages/aiohttp/web_protocol.py", line 452, in _handle_request resp = await request_handler(request) File "/usr/local/lib/python3.12/site-packages/aiohttp/web_app.py", line 543, in _handle resp = await handler(request) File "/usr/local/lib/python3.12/site-packages/aiohttp/web_middlewares.py", line 114, in impl return await handler(request) File "/usr/src/homeassistant/homeassistant/components/http/security_filter.py", line 92, in security_filter_middleware return await handler(request) File "/usr/src/homeassistant/homeassistant/components/http/forwarded.py", line 210, in forwarded_middleware return await handler(request) File "/usr/src/homeassistant/homeassistant/components/http/request_context.py", line 26, in request_context_middleware return await handler(request) File "/usr/src/homeassistant/homeassistant/components/http/ban.py", line 85, in ban_middleware return await handler(request) File "/usr/src/homeassistant/homeassistant/components/http/auth.py", line 242, in auth_middleware return await handler(request) File "/usr/src/homeassistant/homeassistant/components/http/headers.py", line 32, in headers_middleware response = await handler(request) File "/usr/src/homeassistant/homeassistant/helpers/http.py", line 73, in handle result = await handler(request, **request.match_info) File "/usr/src/homeassistant/homeassistant/components/config/config_entries.py", line 120, in post await hass.config_entries.async_reload(entry_id)

Still pointing to the 'config' integration and pysocket, not OTGW strictly :/

[andriej]

@mvn23 it has to be something left in the code that makes pyserial-asyncio-fast not fully effective. Maybe asyncio lib preloads something from pyserial that is still used? I don't know how can I help further debug...

[mvn23]

Possibly caused by home-assistant-libs/pyserial-asyncio-fast#12 It makes sense if your gateway only accepts 1 simultaneous connection and refuses any attempts exceeding that.

However, it does not explain the blocking call message. Are we sure this is coming from opentherm_gw?

[andriej]

My gateway interface only accepts one connection indeed.

I'm almost certainly sure as it's also the same in "safe mode" where all customs are OFF. None other integration (I use in HA) uses socket AFAIR

[andriej]

I see the lib-fix merged, keep fingers crossed for fix. :-)