search

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.93k stars 30.99k forks source link

OTGW suddenly stopt. Not able to start it again. #113443

Closed ArJay60 closed 6 months ago

ArJay60 commented 8 months ago

The problem

OTGW suddenly stopt working. Not able to reload or start after restarting HA.

What version of Home Assistant Core has the issue?

2024.3.1

What was the last working version of Home Assistant Core?

2024.3.1

What type of installation are you running?

Home Assistant OS

Integration causing the issue

OTGW

Link to integration documentation on our website

No response

Diagnostics information

Logger: homeassistant Source: util/async_.py:124 First occurred: 19:47:40 (1 occurrences) Last logged: 19:47:40

Error doing job: Exception in callback SerialTransport._call_connectionlost(None) Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/util/async.py", line 120, in check_loop integration_frame = get_integration_frame() ^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/frame.py", line 61, in get_integration_frame raise MissingIntegrationFrame homeassistant.helpers.frame.MissingIntegrationFrame

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "/usr/local/lib/python3.12/asyncio/events.py", line 84, in _run self._context.run(self._callback, *self._args) File "/usr/local/lib/python3.12/site-packages/serial_asyncio/init.py", line 417, in _call_connection_lost self._serial.close() File "/usr/local/lib/python3.12/site-packages/serial/urlhandler/protocolsocket.py", line 104, in close time.sleep(0.3) File "/usr/src/homeassistant/homeassistant/util/async.py", line 169, in protected_loop_func checkloop(func, strict=strict) File "/usr/src/homeassistant/homeassistant/util/async.py", line 124, in check_loop raise RuntimeError( # noqa: TRY200 RuntimeError: Detected blocking call to sleep inside the event loop. Use await hass.async_add_executor_job(); This is causing stability issues. Please create a bug report at https://github.com/home-assistant/core/issues?q=is%3Aopen+is%3Aissue

Example YAML snippet

No response

Anything in the logs that might be useful for us?

Logger: homeassistant
Source: util/async_.py:124
First occurred: 19:47:40 (1 occurrences)
Last logged: 19:47:40

Error doing job: Exception in callback SerialTransport._call_connection_lost(None)
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/util/async_.py", line 120, in check_loop
    integration_frame = get_integration_frame()
                        ^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/frame.py", line 61, in get_integration_frame
    raise MissingIntegrationFrame
homeassistant.helpers.frame.MissingIntegrationFrame

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.12/asyncio/events.py", line 84, in _run
    self._context.run(self._callback, *self._args)
  File "/usr/local/lib/python3.12/site-packages/serial_asyncio/__init__.py", line 417, in _call_connection_lost
    self._serial.close()
  File "/usr/local/lib/python3.12/site-packages/serial/urlhandler/protocol_socket.py", line 104, in close
    time.sleep(0.3)
  File "/usr/src/homeassistant/homeassistant/util/async_.py", line 169, in protected_loop_func
    check_loop(func, strict=strict)
  File "/usr/src/homeassistant/homeassistant/util/async_.py", line 124, in check_loop
    raise RuntimeError(  # noqa: TRY200
RuntimeError: Detected blocking call to sleep inside the event loop. Use `await hass.async_add_executor_job()`; This is causing stability issues. Please create a bug report at https://github.com/home-assistant/core/issues?q=is%3Aopen+is%3Aissue

Additional information

No response

home-assistant[bot] commented 8 months 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!

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 commented 8 months ago

The log entry is unfortunately not related to your issue. It is the result of a known issue in pyserial-asyncio (see https://github.com/pyserial/pyserial-asyncio/issues/81 and https://github.com/pyserial/pyserial-asyncio/issues/102).

To troubleshoot your issue, can you post a debug log of an integration reload?

pixelspark commented 8 months ago

I am seeing a similar error just below a message about a serial connection to my OTGW, which is why I suspect the get_integration_frame error is related to OTGW:

2024-03-17 22:38:11.264 ERROR (MainThread) [pyotgw.connection] The serial device on socket://10.10.3.1:6639 is not responding. Will keep trying.
2024-03-17 22:38:11.266 ERROR (MainThread) [homeassistant] Error doing job: Exception in callback SerialTransport._call_connection_lost(None)
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/util/async_.py", line 150, in check_loop
    integration_frame = get_integration_frame()
                        ^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/frame.py", line 81, in get_integration_frame
    raise MissingIntegrationFrame
homeassistant.helpers.frame.MissingIntegrationFrame

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  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/serial_asyncio/__init__.py", line 417, in _call_connection_lost
    self._serial.close()
  File "/usr/local/lib/python3.12/site-packages/serial/urlhandler/protocol_socket.py", line 104, in close
    time.sleep(0.3)
  File "/usr/src/homeassistant/homeassistant/util/async_.py", line 199, in protected_loop_func
    check_loop(func, strict=strict)
  File "/usr/src/homeassistant/homeassistant/util/async_.py", line 154, in check_loop
    raise RuntimeError(  # noqa: TRY200
RuntimeError: Detected blocking call to sleep inside the event loop. Use `await hass.async_add_executor_job()`; This is causing stability issues. Please create a bug report at https://github.com/home-assistant/core/issues?q=is%3Aopen+is%3Aissue
mvn23 commented 8 months ago

The blocking call error is indeed related to the OpenTherm Gateway integration, but it is not causing the issue you're having. However, this line:

2024-03-17 22:38:11.264 ERROR (MainThread) [pyotgw.connection] The serial device on socket://10.10.3.1:6639 is not responding. Will keep trying.

indicates that Home Assistant is not receiving any replies from the gateway. Please try to power cycle the gateway and/or see if you can still connect using e.g. otmonitor.

ArJay60 commented 8 months ago

I tried power cycling the gateway but no result. Tried to reinstall the Opentherm Add On in HA to reconfigure but no luck on installing. Same error messages as above. The Diagnostics window of OTMonitor is continuously spitting its lines. So it looks like is has to be on the HA side.

mvn23 commented 8 months ago

In that case we're going to need that debug log.

ArJay60 commented 8 months ago

Logger: pyotgw.connection Bron: runner.py:188 First occurred: 09:26:23 (1 gebeurtenissen) Laatst gelogd: 09:26:23

Could not connect to serial device on socket://192.168.1.13;23. Will keep trying. Reported error was: Could not open port socket://192.168.1.13;23: '<=' not supported between instances of 'int' and 'NoneType'

2024-03-19 09:10:18.268 ERROR (MainThread) [homeassistant] Error doing job: Exception in callback SerialTransport._call_connection_lost(None)

Traceback (most recent call last):

File "/usr/src/homeassistant/homeassistant/util/async_.py", line 150, in check_loop

integration_frame = get_integration_frame()

^^^^^^^^^^^^^^^^^^^^^^^

File "/usr/src/homeassistant/homeassistant/helpers/frame.py", line 81, in get_integration_frame

raise MissingIntegrationFrame

homeassistant.helpers.frame.MissingIntegrationFrame

During handling of the above exception, another exception occurred:

Traceback (most recent call last):

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/serial_asyncio/init.py", line 417, in _call_connection_lost

self._serial.close()

File "/usr/local/lib/python3.12/site-packages/serial/urlhandler/protocol_socket.py", line 104, in close

time.sleep(0.3)

File "/usr/src/homeassistant/homeassistant/util/async_.py", line 199, in protected_loop_func

check_loop(func, strict=strict)

File "/usr/src/homeassistant/homeassistant/util/async_.py", line 154, in check_loop

raise RuntimeError( # noqa: TRY200

RuntimeError: Detected blocking call to sleep inside the event loop. Use await hass.async_add_executor_job(); This is causing stability issues. Please create a bug report at https://github.com/home-assistant/core/issues?q=is%3Aopen+is%3Aissue

2024-03-19 09:10:21.421 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: A.

2024-03-19 09:10:24.425 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: B.

2024-03-19 09:10:27.427 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: C.

2024-03-19 09:10:30.430 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: W.

2024-03-19 09:10:33.432 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: G.

2024-03-19 09:10:36.435 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: I.

2024-03-19 09:10:39.437 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: L.

2024-03-19 09:10:42.438 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: M.

2024-03-19 09:10:45.441 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: Q.

2024-03-19 09:10:48.443 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: S.

2024-03-19 09:10:51.444 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: O.

2024-03-19 09:10:54.448 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: P.

2024-03-19 09:10:57.451 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: D.

2024-03-19 09:11:00.452 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: R.

2024-03-19 09:11:03.454 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: T.

2024-03-19 09:11:06.456 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: V.

2024-03-19 09:11:09.462 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PS, value: 1.

2024-03-19 09:15:24.866 WARNING (MainThread) [homeassistant.components.mqtt.light.schema_json] Invalid color mode 'xy' received for entity light.slaapkamer_uplight

2024-03-19 09:21:27.856 WARNING (MainThread) [homeassistant.components.mqtt.light.schema_json] Invalid color mode 'xy' received for entity light.slaapkamer_uplight

2024-03-19 09:26:23.717 ERROR (MainThread) [pyotgw.connection] Could not connect to serial device on socket://192.168.1.13;23. Will keep trying. Reported error was: Could not open port socket://192.168.1.13;23: '<=' not supported between instances of 'int' and 'NoneType'

mvn23 commented 8 months ago

Please change the url to socket://192.168.1.13:23 (note the : instead of the ;) and try again.

edit: also, please enable debug logging. Just errors and warnings may not be enough.

ArJay60 commented 8 months ago

Made a mistake in socket in above log. Log below is with correct socket definition

2024-03-19 13:28:07.011 ERROR (MainThread) [homeassistant] Error doing job: Exception in callback SerialTransport._call_connectionlost(None) Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/util/async.py", line 150, in check_loop integration_frame = get_integration_frame() ^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/frame.py", line 81, in get_integration_frame raise MissingIntegrationFrame homeassistant.helpers.frame.MissingIntegrationFrame During handling of the above exception, another exception occurred: Traceback (most recent call last): 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/serial_asyncio/init.py", line 417, in _call_connection_lost self._serial.close() File "/usr/local/lib/python3.12/site-packages/serial/urlhandler/protocolsocket.py", line 104, in close time.sleep(0.3) File "/usr/src/homeassistant/homeassistant/util/async.py", line 199, in protected_loop_func checkloop(func, strict=strict) File "/usr/src/homeassistant/homeassistant/util/async.py", line 154, in check_loop raise RuntimeError( # noqa: TRY200 RuntimeError: Detected blocking call to sleep inside the event loop. Use await hass.async_add_executor_job(); This is causing stability issues. Please create a bug report at https://github.com/home-assistant/core/issues?q=is%3Aopen+is%3Aissue

ArJay60 commented 8 months ago

How do I enable debug logging for Openthem when the integration is not visible on the integration page?

ArJay60 commented 8 months ago

Restored a version where the OpenTherm Integration was still available. Debug log below. Is this enough?

2024-03-19 19:20:03.644 WARNING (SyncWorker_3) [homeassistant.loader] We found a custom integration webrtc 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 2024-03-19 19:20:03.648 WARNING (SyncWorker_3) [homeassistant.loader] We found a custom integration tapo_control 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 2024-03-19 19:20:03.650 WARNING (SyncWorker_3) [homeassistant.loader] We found a custom integration smartthinq_sensors 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 2024-03-19 19:20:03.652 WARNING (SyncWorker_3) [homeassistant.loader] We found a custom integration hacs 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 2024-03-19 19:20:06.027 WARNING (Recorder) [homeassistant.components.recorder.util] The system could not validate that the sqlite3 database at //config/home-assistant_v2.db was shutdown cleanly 2024-03-19 19:20:06.052 WARNING (Recorder) [homeassistant.components.recorder.util] Ended unfinished session (id=11 from 2024-02-25 16:39:20.615565) 2024-03-19 19:20:19.643 WARNING (MainThread) [py.warnings] /usr/local/lib/python3.12/site-packages/telegram/utils/request.py:49: UserWarning: python-telegram-bot is using upstream urllib3. This is allowed but not supported by python-telegram-bot maintainers. warnings.warn(

2024-03-19 19:20:20.160 WARNING (MainThread) [rflink.protocol] dropping invalid data: 20;01;NodoNRF=ON; 2024-03-19 19:20:20.160 WARNING (MainThread) [rflink.protocol] dropping invalid data: 20;02;BLE=OFF;NO NRF24L01; 2024-03-19 19:20:23.067 ERROR (MainThread) [homeassistant.components.binary_sensor] rpi_power: Error on device update! Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 599, in _async_add_entity await entity.async_device_update(warning=False) File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 1261, in async_device_update await hass.async_add_executor_job(self.update) File "/usr/local/lib/python3.12/concurrent/futures/thread.py", line 58, in run result = self.fn(*self.args, **self.kwargs) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/components/rpi_power/binary_sensor.py", line 52, in update value = self._under_voltage.get() ^^^^^^^^^^^^^^^^^^^^^^^ AttributeError: 'NoneType' object has no attribute 'get' 2024-03-19 19:20:24.775 WARNING (MainThread) [homeassistant.components.switch] Platform broadlink not ready yet: None; Retrying in background in 30 seconds 2024-03-19 19:20:26.377 WARNING (MainThread) [homeassistant.helpers.template] Template variable warning: 'str object' has no attribute 'x' when rendering '{{ value.x }}' 2024-03-19 19:20:27.078 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: CS, value: 0. 2024-03-19 19:20:28.365 WARNING (MainThread) [homeassistant.components.climate] Entity None (<class 'custom_components.smartthinq_sensors.climate.LGEACClimate'>) does not set ClimateEntityFeature.TURN_OFF but implements the turn_off method. Please create a bug report at https://github.com/ollo69/ha-smartthinq-sensors/issues 2024-03-19 19:20:28.366 WARNING (MainThread) [homeassistant.components.climate] Entity None (<class 'custom_components.smartthinq_sensors.climate.LGEACClimate'>) does not set ClimateEntityFeature.TURN_ON but implements the turn_on method. Please create a bug report at https://github.com/ollo69/ha-smartthinq-sensors/issues 2024-03-19 19:20:28.366 WARNING (MainThread) [homeassistant.components.climate] Entity None (<class 'custom_components.smartthinq_sensors.climate.LGEACClimate'>) implements HVACMode(s): off, heat, dry, cool, fan_only, heat_cool and therefore implicitly supports the turn_on/turn_off methods without setting the proper ClimateEntityFeature. Please create a bug report at https://github.com/ollo69/ha-smartthinq-sensors/issues 2024-03-19 19:20:28.367 WARNING (MainThread) [homeassistant.components.climate] Entity None (<class 'custom_components.smartthinq_sensors.climate.LGEACClimate'>) does not set ClimateEntityFeature.TURN_OFF but implements the turn_off method. Please create a bug report at https://github.com/ollo69/ha-smartthinq-sensors/issues 2024-03-19 19:20:28.368 WARNING (MainThread) [homeassistant.components.climate] Entity None (<class 'custom_components.smartthinq_sensors.climate.LGEACClimate'>) does not set ClimateEntityFeature.TURN_ON but implements the turn_on method. Please create a bug report at https://github.com/ollo69/ha-smartthinq-sensors/issues 2024-03-19 19:20:28.368 WARNING (MainThread) [homeassistant.components.climate] Entity None (<class 'custom_components.smartthinq_sensors.climate.LGEACClimate'>) implements HVACMode(s): off, heat, dry, cool, fan_only, heat_cool and therefore implicitly supports the turn_on/turn_off methods without setting the proper ClimateEntityFeature. Please create a bug report at https://github.com/ollo69/ha-smartthinq-sensors/issues 2024-03-19 19:20:28.370 WARNING (MainThread) [homeassistant.components.climate] Entity None (<class 'custom_components.smartthinq_sensors.climate.LGEACClimate'>) does not set ClimateEntityFeature.TURN_OFF but implements the turn_off method. Please create a bug report at https://github.com/ollo69/ha-smartthinq-sensors/issues 2024-03-19 19:20:28.374 WARNING (MainThread) [homeassistant.components.climate] Entity None (<class 'custom_components.smartthinq_sensors.climate.LGEACClimate'>) does not set ClimateEntityFeature.TURN_ON but implements the turn_on method. Please create a bug report at https://github.com/ollo69/ha-smartthinq-sensors/issues 2024-03-19 19:20:28.375 WARNING (MainThread) [homeassistant.components.climate] Entity None (<class 'custom_components.smartthinq_sensors.climate.LGEACClimate'>) implements HVACMode(s): off, heat, dry, cool, fan_only, heat_cool and therefore implicitly supports the turn_on/turn_off methods without setting the proper ClimateEntityFeature. Please create a bug report at https://github.com/ollo69/ha-smartthinq-sensors/issues 2024-03-19 19:20:30.079 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: MM, value: -. 2024-03-19 19:20:30.658 ERROR (MainThread) [homeassistant] Error doing job: Exception in callback SerialTransport._call_connectionlost(None) Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/util/async.py", line 120, in check_loop integration_frame = get_integration_frame() ^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/frame.py", line 61, in get_integration_frame raise MissingIntegrationFrame homeassistant.helpers.frame.MissingIntegrationFrame

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "/usr/local/lib/python3.12/asyncio/events.py", line 84, in _run self._context.run(self._callback, *self._args) File "/usr/local/lib/python3.12/site-packages/serial_asyncio/init.py", line 417, in _call_connection_lost self._serial.close() File "/usr/local/lib/python3.12/site-packages/serial/urlhandler/protocolsocket.py", line 104, in close time.sleep(0.3) File "/usr/src/homeassistant/homeassistant/util/async.py", line 169, in protected_loop_func checkloop(func, strict=strict) File "/usr/src/homeassistant/homeassistant/util/async.py", line 124, in check_loop raise RuntimeError( # noqa: TRY200 RuntimeError: Detected blocking call to sleep inside the event loop. Use await hass.async_add_executor_job(); This is causing stability issues. Please create a bug report at https://github.com/home-assistant/core/issues?q=is%3Aopen+is%3Aissue 2024-03-19 19:20:47.087 WARNING (MainThread) [homeassistant.components.ssdp] Could not set up UPnP/SSDP server, as a presentation URL could not be determined; Please configure your internal URL in the Home Assistant general configuration 2024-03-19 19:20:50.838 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: A. 2024-03-19 19:20:53.842 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: B. 2024-03-19 19:20:56.843 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: C. 2024-03-19 19:21:00.133 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: CS, value: 0. 2024-03-19 19:21:03.135 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: MM, value: -. 2024-03-19 19:21:03.138 ERROR (MainThread) [homeassistant] Error doing job: Exception in callback SerialTransport._call_connectionlost(None) Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/util/async.py", line 120, in check_loop integration_frame = get_integration_frame() ^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/frame.py", line 61, in get_integration_frame raise MissingIntegrationFrame homeassistant.helpers.frame.MissingIntegrationFrame

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "/usr/local/lib/python3.12/asyncio/events.py", line 84, in _run self._context.run(self._callback, *self._args) File "/usr/local/lib/python3.12/site-packages/serial_asyncio/init.py", line 417, in _call_connection_lost self._serial.close() File "/usr/local/lib/python3.12/site-packages/serial/urlhandler/protocolsocket.py", line 104, in close time.sleep(0.3) File "/usr/src/homeassistant/homeassistant/util/async.py", line 169, in protected_loop_func checkloop(func, strict=strict) File "/usr/src/homeassistant/homeassistant/util/async.py", line 124, in check_loop raise RuntimeError( # noqa: TRY200 RuntimeError: Detected blocking call to sleep inside the event loop. Use await hass.async_add_executor_job(); This is causing stability issues. Please create a bug report at https://github.com/home-assistant/core/issues?q=is%3Aopen+is%3Aissue 2024-03-19 19:21:16.851 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: A. 2024-03-19 19:21:19.865 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: B. 2024-03-19 19:21:20.463 WARNING (MainThread) [homeassistant.components.mqtt.light.schema_json] Invalid color mode 'xy' received for entity light.slaapkamer_uplight 2024-03-19 19:21:22.872 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: C. 2024-03-19 19:21:26.295 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: CS, value: 0. 2024-03-19 19:21:29.296 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: MM, value: -. 2024-03-19 19:21:29.300 ERROR (MainThread) [homeassistant] Error doing job: Exception in callback SerialTransport._call_connectionlost(None) Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/util/async.py", line 120, in check_loop integration_frame = get_integration_frame() ^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/frame.py", line 61, in get_integration_frame raise MissingIntegrationFrame homeassistant.helpers.frame.MissingIntegrationFrame

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "/usr/local/lib/python3.12/asyncio/events.py", line 84, in _run self._context.run(self._callback, *self._args) File "/usr/local/lib/python3.12/site-packages/serial_asyncio/init.py", line 417, in _call_connection_lost self._serial.close() File "/usr/local/lib/python3.12/site-packages/serial/urlhandler/protocolsocket.py", line 104, in close time.sleep(0.3) File "/usr/src/homeassistant/homeassistant/util/async.py", line 169, in protected_loop_func checkloop(func, strict=strict) File "/usr/src/homeassistant/homeassistant/util/async.py", line 124, in check_loop raise RuntimeError( # noqa: TRY200 RuntimeError: Detected blocking call to sleep inside the event loop. Use await hass.async_add_executor_job(); This is causing stability issues. Please create a bug report at https://github.com/home-assistant/core/issues?q=is%3Aopen+is%3Aissue 2024-03-19 19:21:49.549 DEBUG (MainThread) [pyotgw.status] Starting reporting routine 2024-03-19 19:21:49.580 DEBUG (MainThread) [pyotgw.commandprocessor] Serial transport closed, not sending command PS 2024-03-19 19:21:49.874 DEBUG (MainThread) [pyotgw.protocol] Received line 1: T00110000 2024-03-19 19:21:49.875 DEBUG (MainThread) [pyotgw.messageprocessor] Added line to message queue. Queue size: 1 2024-03-19 19:21:49.875 DEBUG (MainThread) [pyotgw.messageprocessor] Processing: T 00 11 00 00 2024-03-19 19:21:49.875 DEBUG (MainThread) [pyotgw.connection] Connected to serial device on socket://192.168.1.13:23 2024-03-19 19:21:49.875 DEBUG (MainThread) [pyotgw.commandprocessor] Sending command: PR with value A 2024-03-19 19:21:50.019 DEBUG (MainThread) [pyotgw.protocol] Received line 2: BC0110000 2024-03-19 19:21:50.019 DEBUG (MainThread) [pyotgw.messageprocessor] Added line to message queue. Queue size: 1 2024-03-19 19:21:50.020 DEBUG (MainThread) [pyotgw.messageprocessor] Processing: B 04 11 00 00 2024-03-19 19:21:50.020 DEBUG (MainThread) [pyotgw.connection] Watchdog timer reset! 2024-03-19 19:21:50.887 DEBUG (MainThread) [pyotgw.protocol] Received line 3: T80190000 2024-03-19 19:21:50.887 DEBUG (MainThread) [pyotgw.messageprocessor] Added line to message queue. Queue size: 1 2024-03-19 19:21:50.887 DEBUG (MainThread) [pyotgw.messageprocessor] Processing: T 00 19 00 00 2024-03-19 19:21:50.888 DEBUG (MainThread) [pyotgw.connection] Watchdog timer reset! 2024-03-19 19:21:51.019 DEBUG (MainThread) [pyotgw.protocol] Received line 4: B40193533 2024-03-19 19:21:51.020 DEBUG (MainThread) [pyotgw.messageprocessor] Added line to message queue. Queue size: 1 2024-03-19 19:21:51.020 DEBUG (MainThread) [pyotgw.messageprocessor] Processing: B 04 19 35 33 2024-03-19 19:21:51.020 DEBUG (MainThread) [pyotgw.connection] Watchdog timer reset! 2024-03-19 19:21:51.885 DEBUG (MainThread) [pyotgw.protocol] Received line 5: T80640000 2024-03-19 19:21:51.886 DEBUG (MainThread) [pyotgw.messageprocessor] Added line to message queue. Queue size: 1 2024-03-19 19:21:51.886 DEBUG (MainThread) [pyotgw.protocol] Received line 6: R007B0000 2024-03-19 19:21:51.887 DEBUG (MainThread) [pyotgw.messageprocessor] Added line to message queue. Queue size: 2 2024-03-19 19:21:51.888 DEBUG (MainThread) [pyotgw.messageprocessor] Processing: T 00 64 00 00 2024-03-19 19:21:51.888 DEBUG (MainThread) [pyotgw.messageprocessor] Processing: R 00 7B 00 00 2024-03-19 19:21:51.888 DEBUG (MainThread) [pyotgw.connection] Watchdog timer reset! 2024-03-19 19:21:51.889 DEBUG (MainThread) [pyotgw.connection] Watchdog timer reset! 2024-03-19 19:21:52.231 DEBUG (MainThread) [pyotgw.protocol] Received line 7: BC07B0291 2024-03-19 19:21:52.232 DEBUG (MainThread) [pyotgw.messageprocessor] Added line to message queue. Queue size: 1 2024-03-19 19:21:52.232 DEBUG (MainThread) [pyotgw.protocol] Received line 8: A40640000 2024-03-19 19:21:52.232 DEBUG (MainThread) [pyotgw.messageprocessor] Added line to message queue. Queue size: 2 2024-03-19 19:21:52.232 DEBUG (MainThread) [pyotgw.messageprocessor] Processing: B 04 7B 02 91 2024-03-19 19:21:52.232 DEBUG (MainThread) [pyotgw.messageprocessor] Processing: A 04 64 00 00 2024-03-19 19:21:52.250 DEBUG (MainThread) [pyotgw.connection] Watchdog timer reset! 2024-03-19 19:21:52.250 DEBUG (MainThread) [pyotgw.connection] Watchdog timer reset! 2024-03-19 19:21:52.876 DEBUG (MainThread) [pyotgw.protocol] Received line 9: T80000200 2024-03-19 19:21:52.876 DEBUG (MainThread) [pyotgw.messageprocessor] Added line to message queue. Queue size: 1 2024-03-19 19:21:52.877 DEBUG (MainThread) [pyotgw.messageprocessor] Processing: T 00 00 02 00 2024-03-19 19:21:52.877 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: A. 2024-03-19 19:21:52.877 DEBUG (MainThread) [pyotgw.commandprocessor] Sending command: PR with value B 2024-03-19 19:21:52.890 DEBUG (MainThread) [pyotgw.connection] Watchdog timer reset! 2024-03-19 19:21:53.014 DEBUG (MainThread) [pyotgw.protocol] Received line 10: B40000200 2024-03-19 19:21:53.014 DEBUG (MainThread) [pyotgw.messageprocessor] Added line to message queue. Queue size: 1 2024-03-19 19:21:53.014 DEBUG (MainThread) [pyotgw.messageprocessor] Processing: B 04 00 02 00 2024-03-19 19:21:53.015 DEBUG (MainThread) [pyotgw.connection] Watchdog timer reset! 2024-03-19 19:21:53.873 DEBUG (MainThread) [pyotgw.protocol] Received line 11: T10010600 2024-03-19 19:21:53.873 DEBUG (MainThread) [pyotgw.messageprocessor] Added line to message queue. Queue size: 1 2024-03-19 19:21:53.874 DEBUG (MainThread) [pyotgw.messageprocessor] Processing: T 01 01 06 00 2024-03-19 19:21:53.874 DEBUG (MainThread) [pyotgw.connection] Watchdog timer reset! 2024-03-19 19:21:54.019 DEBUG (MainThread) [pyotgw.protocol] Received line 12: BD0010600 2024-03-19 19:21:54.020 DEBUG (MainThread) [pyotgw.messageprocessor] Added line to message queue. Queue size: 1 2024-03-19 19:21:54.020 DEBUG (MainThread) [pyotgw.messageprocessor] Processing: B 05 01 06 00 2024-03-19 19:21:54.021 DEBUG (MainThread) [pyotgw.connection] Watchdog timer reset! 2024-03-19 19:21:54.877 DEBUG (MainThread) [pyotgw.protocol] Received line 13: T00110000 2024-03-19 19:21:54.877 DEBUG (MainThread) [pyotgw.messageprocessor] Added line to message queue. Queue size: 1 2024-03-19 19:21:54.878 DEBUG (MainThread) [pyotgw.messageprocessor] Processing: T 00 11 00 00 2024-03-19 19:21:54.878 DEBUG (MainThread) [pyotgw.connection] Watchdog timer reset! 2024-03-19 19:21:55.020 DEBUG (MainThread) [pyotgw.protocol] Received line 14: BC0110000 2024-03-19 19:21:55.020 DEBUG (MainThread) [pyotgw.messageprocessor] Added line to message queue. Queue size: 1 2024-03-19 19:21:55.020 DEBUG (MainThread) [pyotgw.messageprocessor] Processing: B 04 11 00 00 2024-03-19 19:21:55.023 DEBUG (MainThread) [pyotgw.connection] Watchdog timer reset! 2024-03-19 19:21:55.880 DEBUG (MainThread) [pyotgw.protocol] Received line 15: T80190000 2024-03-19 19:21:55.881 DEBUG (MainThread) [pyotgw.messageprocessor] Added line to message queue. Queue size: 1 2024-03-19 19:21:55.881 DEBUG (MainThread) [pyotgw.messageprocessor] Processing: T 00 19 00 00 2024-03-19 19:21:55.881 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: B. 2024-03-19 19:21:55.881 DEBUG (MainThread) [pyotgw.commandprocessor] Sending command: PR with value C 2024-03-19 19:21:55.882 DEBUG (MainThread) [pyotgw.connection] Watchdog timer reset! 2024-03-19 19:21:56.009 DEBUG (MainThread) [pyotgw.protocol] Received line 16: B40193533 2024-03-19 19:21:56.010 DEBUG (MainThread) [pyotgw.messageprocessor] Added line to message queue. Queue size: 1 2024-03-19 19:21:56.010 DEBUG (MainThread) [pyotgw.messageprocessor] Processing: B 04 19 35 33 2024-03-19 19:21:56.011 DEBUG (MainThread) [pyotgw.connection] Watchdog timer reset! 2024-03-19 19:21:56.878 DEBUG (MainThread) [pyotgw.protocol] Received line 17: T00050000 2024-03-19 19:21:56.878 DEBUG (MainThread) [pyotgw.messageprocessor] Added line to message queue. Queue size: 1 2024-03-19 19:21:56.878 DEBUG (MainThread) [pyotgw.messageprocessor] Processing: T 00 05 00 00 2024-03-19 19:21:56.879 DEBUG (MainThread) [pyotgw.connection] Watchdog timer reset! 2024-03-19 19:21:57.009 DEBUG (MainThread) [pyotgw.protocol] Received line 18: BC00500FF 2024-03-19 19:21:57.009 DEBUG (MainThread) [pyotgw.messageprocessor] Added line to message queue. Queue size: 1 2024-03-19 19:21:57.010 DEBUG (MainThread) [pyotgw.messageprocessor] Processing: B 04 05 00 FF 2024-03-19 19:21:57.010 DEBUG (MainThread) [pyotgw.connection] Watchdog timer reset! 2024-03-19 19:21:57.874 DEBUG (MainThread) [pyotgw.protocol] Received line 19: T80000200 2024-03-19 19:21:57.874 DEBUG (MainThread) [pyotgw.messageprocessor] Added line to message queue. Queue size: 1 2024-03-19 19:21:57.877 DEBUG (MainThread) [pyotgw.messageprocessor] Processing: T 00 00 02 00 2024-03-19 19:21:57.878 DEBUG (MainThread) [pyotgw.connection] Watchdog timer reset! 2024-03-19 19:21:58.022 DEBUG (MainThread) [pyotgw.protocol] Received line 20: B40000200 2024-03-19 19:21:58.022 DEBUG (MainThread) [pyotgw.messageprocessor] Added line to message queue. Queue size: 1 2024-03-19 19:21:58.023 DEBUG (MainThread) [pyotgw.messageprocessor] Processing: B 04 00 02 00 2024-03-19 19:21:58.026 DEBUG (MainThread) [pyotgw.connection] Watchdog timer reset! 2024-03-19 19:21:58.878 DEBUG (MainThread) [pyotgw.protocol] Received line 21: T10010600 2024-03-19 19:21:58.878 DEBUG (MainThread) [pyotgw.messageprocessor] Added line to message queue. Queue size: 1 2024-03-19 19:21:58.878 DEBUG (MainThread) [pyotgw.messageprocessor] Processing: T 01 01 06 00 2024-03-19 19:21:58.896 DEBUG (MainThread) [pyotgw.connection] Watchdog timer reset! 2024-03-19 19:21:58.896 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: PR, value: C. 2024-03-19 19:21:58.896 DEBUG (MainThread) [pyotgw.commandprocessor] Sending command: PR with value W 2024-03-19 19:21:59.005 DEBUG (MainThread) [pyotgw.protocol] Received line 22: BD0010600 2024-03-19 19:21:59.006 DEBUG (MainThread) [pyotgw.messageprocessor] Added line to message queue. Queue size: 1 2024-03-19 19:21:59.009 DEBUG (MainThread) [pyotgw.messageprocessor] Processing: B 05 01 06 00 2024-03-19 19:21:59.014 DEBUG (MainThread) [pyotgw.connection] Watchdog timer reset! 2024-03-19 19:21:59.556 DEBUG (MainThread) [pyotgw.commandprocessor] Sending command: CS with value 0 2024-03-19 19:21:59.877 DEBUG (MainThread) [pyotgw.protocol] Received line 23: T00110000 2024-03-19 19:21:59.878 DEBUG (MainThread) [pyotgw.messageprocessor] Added line to message queue. Queue size: 1 2024-03-19 19:21:59.878 DEBUG (MainThread) [pyotgw.messageprocessor] Processing: T 00 11 00 00 2024-03-19 19:21:59.881 DEBUG (MainThread) [pyotgw.connection] Watchdog timer reset! 2024-03-19 19:22:00.008 DEBUG (MainThread) [pyotgw.protocol] Received line 24: BC0110000 2024-03-19 19:22:00.008 DEBUG (MainThread) [pyotgw.messageprocessor] Added line to message queue. Queue size: 1 2024-03-19 19:22:00.010 DEBUG (MainThread) [pyotgw.messageprocessor] Processing: B 04 11 00 00 2024-03-19 19:22:00.010 DEBUG (MainThread) [pyotgw.connection] Watchdog timer reset! 2024-03-19 19:22:00.875 DEBUG (MainThread) [pyotgw.protocol] Received line 25: T80190000 2024-03-19 19:22:00.875 DEBUG (MainThread) [pyotgw.messageprocessor] Added line to message queue. Queue size: 1 2024-03-19 19:22:00.878 DEBUG (MainThread) [pyotgw.messageprocessor] Processing: T 00 19 00 00 2024-03-19 19:22:00.879 DEBUG (MainThread) [pyotgw.connection] Watchdog timer reset! 2024-03-19 19:22:01.004 DEBUG (MainThread) [pyotgw.protocol] Received line 26: B4019352B 2024-03-19 19:22:01.004 DEBUG (MainThread) [pyotgw.messageprocessor] Added line to message queue. Queue size: 1 2024-03-19 19:22:01.006 DEBUG (MainThread) [pyotgw.messageprocessor] Processing: B 04 19 35 2B 2024-03-19 19:22:01.007 DEBUG (MainThread) [pyotgw.connection] Watchdog timer reset! 2024-03-19 19:22:01.879 DEBUG (MainThread) [pyotgw.protocol] Received line 27: T001B0EE6 2024-03-19 19:22:01.879 DEBUG (MainThread) [pyotgw.messageprocessor] Added line to message queue. Queue size: 1 2024-03-19 19:22:01.880 DEBUG (MainThread) [pyotgw.messageprocessor] Processing: T 00 1B 0E E6 2024-03-19 19:22:01.880 DEBUG (MainThread) [pyotgw.connection] Watchdog timer reset! 2024-03-19 19:22:02.002 DEBUG (MainThread) [pyotgw.protocol] Received line 28: BC01B0E4C 2024-03-19 19:22:02.002 DEBUG (MainThread) [pyotgw.messageprocessor] Added line to message queue. Queue size: 1 2024-03-19 19:22:02.002 DEBUG (MainThread) [pyotgw.messageprocessor] Processing: B 04 1B 0E 4C 2024-03-19 19:22:02.003 DEBUG (MainThread) [pyotgw.connection] Watchdog timer reset! 2024-03-19 19:22:02.563 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: CS, value: 0. 2024-03-19 19:22:02.564 DEBUG (MainThread) [pyotgw.commandprocessor] Sending command: MM with value - 2024-03-19 19:22:02.878 DEBUG (MainThread) [pyotgw.protocol] Received line 29: T80000200 2024-03-19 19:22:02.879 DEBUG (MainThread) [pyotgw.messageprocessor] Added line to message queue. Queue size: 1 2024-03-19 19:22:02.879 DEBUG (MainThread) [pyotgw.messageprocessor] Processing: T 00 00 02 00 2024-03-19 19:22:02.880 DEBUG (MainThread) [pyotgw.connection] Watchdog timer reset! 2024-03-19 19:22:03.000 DEBUG (MainThread) [pyotgw.protocol] Received line 30: B40000200 2024-03-19 19:22:03.001 DEBUG (MainThread) [pyotgw.messageprocessor] Added line to message queue. Queue size: 1 2024-03-19 19:22:03.001 DEBUG (MainThread) [pyotgw.messageprocessor] Processing: B 04 00 02 00 2024-03-19 19:22:03.002 DEBUG (MainThread) [pyotgw.connection] Watchdog timer reset! 2024-03-19 19:22:03.891 DEBUG (MainThread) [pyotgw.protocol] Received line 31: T10010600 2024-03-19 19:22:03.891 DEBUG (MainThread) [pyotgw.messageprocessor] Added line to message queue. Queue size: 1 2024-03-19 19:22:03.891 DEBUG (MainThread) [pyotgw.messageprocessor] Processing: T 01 01 06 00 2024-03-19 19:22:03.891 DEBUG (MainThread) [pyotgw.connection] Watchdog timer reset! 2024-03-19 19:22:04.011 DEBUG (MainThread) [pyotgw.protocol] Received line 32: BD0010600 2024-03-19 19:22:04.011 DEBUG (MainThread) [pyotgw.messageprocessor] Added line to message queue. Queue size: 1 2024-03-19 19:22:04.011 DEBUG (MainThread) [pyotgw.messageprocessor] Processing: B 05 01 06 00 2024-03-19 19:22:04.012 DEBUG (MainThread) [pyotgw.connection] Watchdog timer reset! 2024-03-19 19:22:04.878 DEBUG (MainThread) [pyotgw.protocol] Received line 33: T00110000 2024-03-19 19:22:04.879 DEBUG (MainThread) [pyotgw.messageprocessor] Added line to message queue. Queue size: 1 2024-03-19 19:22:04.879 DEBUG (MainThread) [pyotgw.messageprocessor] Processing: T 00 11 00 00 2024-03-19 19:22:04.879 DEBUG (MainThread) [pyotgw.connection] Watchdog timer reset! 2024-03-19 19:22:04.996 DEBUG (MainThread) [pyotgw.protocol] Received line 34: BC0110000 2024-03-19 19:22:04.997 DEBUG (MainThread) [pyotgw.messageprocessor] Added line to message queue. Queue size: 1 2024-03-19 19:22:04.997 DEBUG (MainThread) [pyotgw.messageprocessor] Processing: B 04 11 00 00 2024-03-19 19:22:04.997 DEBUG (MainThread) [pyotgw.connection] Watchdog timer reset! 2024-03-19 19:22:05.569 ERROR (MainThread) [pyotgw.pyotgw] Timed out waiting for command: MM, value: -. 2024-03-19 19:22:05.569 DEBUG (MainThread) [pyotgw.connection] Canceling Watchdog task. 2024-03-19 19:22:05.573 ERROR (MainThread) [homeassistant] Error doing job: Exception in callback SerialTransport._call_connectionlost(None) Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/util/async.py", line 120, in check_loop integration_frame = get_integration_frame() ^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/frame.py", line 61, in get_integration_frame raise MissingIntegrationFrame homeassistant.helpers.frame.MissingIntegrationFrame

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "/usr/local/lib/python3.12/asyncio/events.py", line 84, in _run self._context.run(self._callback, *self._args) File "/usr/local/lib/python3.12/site-packages/serial_asyncio/init.py", line 417, in _call_connection_lost self._serial.close() File "/usr/local/lib/python3.12/site-packages/serial/urlhandler/protocolsocket.py", line 104, in close time.sleep(0.3) File "/usr/src/homeassistant/homeassistant/util/async.py", line 169, in protected_loop_func checkloop(func, strict=strict) File "/usr/src/homeassistant/homeassistant/util/async.py", line 124, in check_loop raise RuntimeError( # noqa: TRY200 RuntimeError: Detected blocking call to sleep inside the event loop. Use await hass.async_add_executor_job(); This is causing stability issues. Please create a bug report at https://github.com/home-assistant/core/issues?q=is%3Aopen+is%3Aissue

mvn23 commented 8 months ago

From the log it looks like you are indeed connected to the gateway and receiving the normal protocol messages, which you also saw in otmonitor, but that's only part of what we need. The problem seems to be that you don't get any response to the commands we're issuing from Home Assistant. Can you check that otmonitor can send commands, e.g. by changing the target temperature and looking for something like this in the log?

10:03:53.279414 Command: TT=20.00
10:03:53.323170 TT: 20.0
ArJay60 commented 8 months ago

Problem is probably in broken connection (crack in track) on pcb in transmit path from wifi to uproc. Intermittently was a able to send when i pushed on pcb. Repaired track and now i have a steady connection. This could also explain why i suddenly lost a working device even when nothing in te config changed. Will monitor if it keeps working but assume it is fixed now. Thanks for putting me in the right direction.

bdraco commented 7 months ago

https://github.com/home-assistant-libs/pyserial-asyncio-fast should not have the blocking issue

lloyda commented 6 months ago

https://github.com/home-assistant-libs/pyserial-asyncio-fast should not have the blocking issue

Can OTGW not be built against that? pyserial-asyncio looks like a dead project. It would be much better to be reliant on something that is part of HA, and so is more likely to be maintained.

mvn23 commented 6 months ago

I've been working on exactly that. A new release of the library was published a few days ago, so when I find the time to test it in HA it will be used here as well.