casakampa commented 2 years ago

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[bot] commented 2 years ago

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

probot-home-assistant[bot] commented 2 years ago

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 commented 2 years ago

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

mvn23 commented 2 years ago

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

mvn23 commented 2 years ago

67419 seems to be affected as well.

pimz3001 commented 2 years ago

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/protocolsocket.py", line 104, in close time.sleep(0.3) File "/usr/src/homeassistant/homeassistant/util/async.py", line 173, in protected_loop_func checkloop(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[bot] commented 2 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 has now been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.

pimz3001 commented 2 years ago

nothing changed so far,

mvn23 commented 2 years ago

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

acfnews commented 1 year ago

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 commented 1 year ago

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 commented 1 year ago

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 commented 1 year ago

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

akula3 commented 1 year ago

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 commented 1 year ago

This has been fixed in pyserial but no release has been made since 2021 https://github.com/pyserial/pyserial-asyncio/pull/82

home-assistant / core

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

The problem

What version of Home Assistant Core has the issue?

What was the last working version of Home Assistant Core?

What type of installation are you running?

Integration causing the issue

Link to integration documentation on our website

Diagnostics information

Example YAML snippet

Anything in the logs that might be useful for us?

Additional information

67419 seems to be affected as well.