Skip to content
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

OpenTherm Gateway: Detected blocking call inside the event loop #67430

Closed
casakampa opened this issue Mar 1, 2022 · 16 comments
Closed

OpenTherm Gateway: Detected blocking call inside the event loop #67430

casakampa opened this issue Mar 1, 2022 · 16 comments

Comments

@casakampa
Copy link

The problem

An log item about the PyOTGW appeared when the connection to my OpenTherm Gateway was somehow disconnected - it's connected to the network by an UTP cable, and no power failure or power cycle or anything else happened when this error appeared. This error has never appeared before.

The OTGW runs firmware version 5.2 for two months now, has a static IP and runs without problems.

What version of Home Assistant Core has the issue?

core-2022.2.9

What was the last working version of Home Assistant Core?

No response

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

Not yet available for this integration

Example YAML snippet

Only YAML that is being used to tell the OTGW what to do:

- id: b5da03a9-99eb-416d-906c-a6acdf4d2781
  alias: "Update OTGW" # OTC is Outside Temperature Control
  description: "Aangezien er geen buitenvoeler op de ketel zit, is dit handig om te gebruiken icm WAR. Met elke update wordt de interne klok gesynchroniseerd"
  trigger:
    - platform: state
      entity_id: sensor.buitentemperatuur
  mode: queued
  condition:
    condition: template
    value_template: >
      {% set ignore = ['unknown', 'unavailable', 'none'] %}
      {{ trigger.to_state.state not in ignore and trigger.to_state.state != trigger.from_state.state }}
  action:
    - alias: "Wanneer de sensor wordt bijgewerkt, update de buitentemperatuur in de OTGW"
      service: opentherm_gw.set_outside_temperature
      data:
        gateway_id: otgw
        temperature: "{{ states('sensor.buitentemperatuur') | float(default=10) }}"
    - alias: "Update de klok tegelijkertijd met de buitentemperatuur"
      service: opentherm_gw.set_clock
      data:
        gateway_id: otgw

Anything in the logs that might be useful for us?

Logger: pyotgw.protocol
Source: /usr/local/lib/python3.9/site-packages/pyotgw/protocol.py:64
First occurred: 27 februari 2022 21:08:15 (1 occurrences)
Last logged: 27 februari 2022 21:08:15

Disconnected: None

Logger: homeassistant
Source: util/async_.py:129
First occurred: 27 februari 2022 21:08:15 (1 occurrences)
Last logged: 27 februari 2022 21:08:15

Error doing job: Exception in callback SerialTransport._call_connection_lost(None)
Traceback (most recent call last):
  File "/usr/local/lib/python3.9/asyncio/events.py", line 80, in _run
    self._context.run(self._callback, *self._args)
  File "/usr/local/lib/python3.9/site-packages/serial_asyncio/__init__.py", line 417, in _call_connection_lost
    self._serial.close()
  File "/usr/local/lib/python3.9/site-packages/serial/urlhandler/protocol_socket.py", line 104, in close
    time.sleep(0.3)
  File "/usr/src/homeassistant/homeassistant/util/async_.py", line 166, in protected_loop_func
    check_loop(func, strict=strict)
  File "/usr/src/homeassistant/homeassistant/util/async_.py", line 129, in check_loop
    raise RuntimeError(
RuntimeError: Detected blocking call inside the event loop. This is causing stability issues. Please report issue

Additional information

No response

@probot-home-assistant
Copy link

opentherm_gw documentation
opentherm_gw source
(message by IssueLinks)

@probot-home-assistant
Copy link

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!
(message by CodeOwnersMention)

@mvn23
Copy link
Contributor

mvn23 commented Mar 1, 2022

Thank you for the report. I will look into the problem.

@mvn23
Copy link
Contributor

mvn23 commented Mar 2, 2022

Seems to be an issue with pyserial-asyncio in the way it handles closing or lost connections.
The issue is reported there.

@mvn23
Copy link
Contributor

mvn23 commented Mar 7, 2022

#67419 seems to be affected as well.

@pimz3001
Copy link

pimz3001 commented Apr 5, 2022

Hi, same problem here. After 3-4 days connection with OT gateway is lost. Only way to get it running again is to restart HA.

File "/usr/local/lib/python3.9/asyncio/events.py", line 80, in _run
self._context.run(self._callback, *self._args)
File "/usr/local/lib/python3.9/site-packages/serial_asyncio/init.py", line 417, in call_connection_lost
self.serial.close()
File "/usr/local/lib/python3.9/site-packages/serial/urlhandler/protocol_socket.py", line 104, in close
time.sleep(0.3)
File "/usr/src/homeassistant/homeassistant/util/async
.py", line 173, in protected_loop_func
check_loop(func, strict=strict)
File "/usr/src/homeassistant/homeassistant/util/async
.py", line 135, in check_loop
raise RuntimeError(
RuntimeError: Detected blocking call to sleep inside the event loop. This is causing stability issues. Please report issue

@github-actions
Copy link

github-actions bot commented Jul 4, 2022

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 has now been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.

@github-actions github-actions bot added the stale label Jul 4, 2022
@pimz3001
Copy link

pimz3001 commented Jul 4, 2022

nothing changed so far,

@github-actions github-actions bot removed the stale label Jul 4, 2022
@mvn23
Copy link
Contributor

mvn23 commented Jul 4, 2022

Still waiting for a new version of pyserial-asyncio...

@acfnews
Copy link

acfnews commented Aug 1, 2022

Just want to mention that with the latest HA 2022.7.7 this is still an issue:

2022-08-01 20:38:03 ERROR (MainThread) [pyotgw.protocol] Disconnected: None
2022-08-01 20:38:03 ERROR (MainThread) [homeassistant] Error doing job: Exception in callback SerialTransport._call_connection_lost(None)
Traceback (most recent call last):
  File "/usr/local/lib/python3.10/asyncio/events.py", line 80, in _run
    self._context.run(self._callback, *self._args)
  File "/usr/local/lib/python3.10/site-packages/serial_asyncio/__init__.py", line 417, in _call_connection_lost
    self._serial.close()
  File "/usr/local/lib/python3.10/site-packages/serial/urlhandler/protocol_socket.py", line 104, in close
    time.sleep(0.3)
  File "/usr/src/homeassistant/homeassistant/util/async_.py", line 180, in protected_loop_func
    check_loop(func, strict=strict)
  File "/usr/src/homeassistant/homeassistant/util/async_.py", line 141, in check_loop
    raise RuntimeError(
RuntimeError: Detected blocking call to sleep inside the event loop. Use `await hass.async_add_executor_job()`; This is causing stability issues. Please report issue

In the container, it seems to use the latest 0.6 version:

# pip freeze | grep pyserial
pyserial==3.5
pyserial-asyncio==0.6

@mvn23
Copy link
Contributor

mvn23 commented Aug 2, 2022

Yep, pyserial-asyncio==0.6 does not include the fix for this yet. As soon as they release a fixed version of pyserial-asyncio we can include it in our dependencies to solve this issue.

@markruys
Copy link

Indeed when I manually remove the time.sleep(0.3), I don't get any blocking calls anymore.

Still I find it strange that so many timeouts occur:

administrator@Alderaan:/volume1/docker/homeassistant$ tail -n 10000 -F home-assistant.log | grep "Timed out"
2022-09-21 22:40:03.284 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: I.
2022-09-21 22:40:06.287 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: L.
2022-09-21 22:40:12.852 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: W.
2022-09-21 22:40:15.855 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: G.
2022-09-21 22:40:21.777 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: MM, value: -.
2022-09-21 22:40:34.951 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: B.
2022-09-21 22:40:37.954 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: C.
2022-09-21 22:40:40.958 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: W.
2022-09-21 22:40:44.782 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: CS, value: 0.
2022-09-21 22:40:47.784 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: MM, value: -.
2022-09-21 22:41:11.302 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: G.
2022-09-21 22:41:14.667 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: S.
2022-09-21 22:41:20.790 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: CS, value: 0.
2022-09-21 22:42:03.919 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: A.
2022-09-21 22:42:06.921 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: B.
2022-09-21 22:42:09.923 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: C.
2022-09-21 22:43:34.315 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: C.
2022-09-21 22:43:37.958 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: S.
2022-09-21 22:43:41.702 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: I.
2022-09-21 22:44:04.822 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: I.
2022-09-21 22:44:17.825 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: I.
2022-09-21 22:44:30.829 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: I.
2022-09-21 22:44:43.833 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: I.
2022-09-21 22:44:56.838 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: I.
2022-09-21 22:45:30.088 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: I.
2022-09-21 22:45:43.096 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: I.
2022-09-21 22:45:56.099 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: I.
2022-09-21 22:46:09.103 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: I.
2022-09-21 22:46:22.106 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: I.
2022-09-21 22:46:35.109 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: I.
2022-09-21 22:46:58.183 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: I.

But I guess that's a different issue.

@markruys
Copy link

About the "Timed out" errors, it's an issue with NodeMCU and firmware r147. I updated to mega-20220809_57b0c0c, and no more time outs.

@issue-triage-workflows
Copy link

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 has now been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.

@issue-triage-workflows issue-triage-workflows bot closed this as not planned Won't fix, can't repro, duplicate, stale Jan 17, 2023
@akula3
Copy link

akula3 commented Feb 2, 2023

The same here:

Logger: homeassistant
Source: util/async_.py:141
First occurred: 1. Februar 2023 um 16:20:25 (101 occurrences)
Last logged: 17:16:02

Error doing job: Exception in callback SerialTransport._call_connection_lost(None)
Traceback (most recent call last):
  File "/usr/local/lib/python3.10/asyncio/events.py", line 80, in _run
    self._context.run(self._callback, *self._args)
  File "/usr/local/lib/python3.10/site-packages/serial_asyncio/__init__.py", line 417, in _call_connection_lost
    self._serial.close()
  File "/usr/local/lib/python3.10/site-packages/serial/urlhandler/protocol_socket.py", line 104, in close
    time.sleep(0.3)
  File "/usr/src/homeassistant/homeassistant/util/async_.py", line 184, in protected_loop_func
    check_loop(func, strict=strict)
  File "/usr/src/homeassistant/homeassistant/util/async_.py", line 141, in check_loop
    raise RuntimeError(
RuntimeError: Detected blocking call to sleep inside the event loop. Use `await hass.async_add_executor_job()`; This is causing stability issues. Please report issue

@bdraco
Copy link
Member

bdraco commented Feb 21, 2023

This has been fixed in pyserial but no release has been made since 2021 pyserial/pyserial-asyncio#82

@github-actions github-actions bot locked and limited conversation to collaborators Mar 23, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

No branches or pull requests

7 participants