Non-thread-safe operation by HA

scharrrfi commented 5 months ago

I agree to the following

[X] I have read the documentation right now
[X] I have read the FAQs right now
[X] I am aware of the latest release notes
[X] I am aware that an integration that was installed via HACS also needs to be updated via HACS
[X] The Backend (CCU/Homegear/...) is working as expected, devices are taught in and are controllable by its own UI.
[X] I am running the latest version of the custom_component (and Home Assistant)

The problem

Hi,

seit dem HA-Update auf 2024.4.0 gibt es massive Probleme, die zu hoher CPU-Last und nach einigen Stunden zum kompletten Crash von HA führen. Ich hatte erst einen Blueprint in Verdacht. Nach weiteren debuggen über den Profiler wie hier empfohlen, sieht es so aus, dass Homematic(IP) Local Integration die Ursache ist.

Ich habe in dem Blueprint die Temperatur meiner Homematic Wetterstation eingebunden. Seitdem ich die Temperatur entfernt habe, scheint Home Assistant wieder stabil zu laufen.

What version of HomematicIP (local) has the issue?

1.58.0

What was the last working version of HomematicIP (local)?

1.58.0

What type of installation are you running?

Home Assistant OS

What type of installation are you running for your homematic backend?

RaspberryMatic HA-Addon

Which version of your homematic backend are you running?

3.75.6.20240316

What hardware are you running for your system?

Proxmox

Which config details do you use

[ ] TLS
[ ] callback data (see)

Which interfaces do you use?

[X] Homematic IP
[X] Homematic (Bidcos-RF)
[ ] Groups (Heating-Group)
[ ] BidCos-Wired (HM-Wired)

Diagnostics information (no logs here)

No response

Log file extract. Anything in the logs that might be useful for us? The log (Setting/System/Logs -> load full log) is the best source to support trouble shooting!


Logger: hahomematic.platforms.entity
Quelle: /usr/local/lib/python3.12/site-packages/hahomematic/platforms/entity.py:236
Erstmals aufgetreten: 21:08:21 (16 Vorkommnisse)
Zuletzt protokolliert: 21:23:54

FIRE_UPDATE_ENTITY_EVENT failed: Non-thread-safe operation invoked on an event loop other than the current one

Logger: asyncio
Quelle: runner.py:189
Erstmals aufgetreten: 21:17:09 (19 Vorkommnisse)
Zuletzt protokolliert: 21:37:27

    Executing <Task pending name='Task-366761' coro=<RequestHandler._handle_request() running at /usr/local/lib/python3.12/site-packages/aiohttp/web_protocol.py:452> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.12/asyncio/base_events.py:448> cb=[Task.task_wakeup()] created at /usr/local/lib/python3.12/site-packages/aiohttp/web_protocol.py:527> took 0.395 seconds
    Executing <TimerHandle when=173252.847228935 _run_async_call_action(<HomeAssistant RUNNING>, <Job call_lat...7f711edf31a0>>) at /usr/src/homeassistant/homeassistant/helpers/event.py:1504 created at /usr/src/homeassistant/homeassistant/helpers/event.py:1551> took 0.441 seconds
    Executing <Task pending name='Task-371798' coro=<RequestHandler._handle_request() running at /usr/local/lib/python3.12/site-packages/aiohttp/web_protocol.py:452> wait_for=<Future pending cb=[_chain_future.<locals>._call_check_cancel() at /usr/local/lib/python3.12/asyncio/futures.py:387, <1 more>, Task.task_wakeup()] created at /usr/local/lib/python3.12/asyncio/base_events.py:448> cb=[Task.task_wakeup()] created at /usr/local/lib/python3.12/site-packages/aiohttp/web_protocol.py:527> took 0.142 seconds
    Executing <Task pending name='admin service automation.reload' coro=<ReloadServiceHelper.execute_service() running at /usr/src/homeassistant/homeassistant/helpers/service.py:1188> wait_for=<Future pending cb=[_chain_future.<locals>._call_check_cancel() at /usr/local/lib/python3.12/asyncio/futures.py:387, <1 more>, Task.task_wakeup()] created at /usr/local/lib/python3.12/asyncio/base_events.py:448> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/util/async_.py:33> took 0.130 seconds
    Executing <Task pending name='admin service automation.reload' coro=<ReloadServiceHelper.execute_service() running at /usr/src/homeassistant/homeassistant/helpers/service.py:1188> wait_for=<_GatheringFuture pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.12/asyncio/tasks.py:712> cb=[set.remove(), Task.task_wakeup()] created at /usr/src/homeassistant/homeassistant/util/async_.py:33> took 0.137 seconds

Additional information

.

SukramJ commented 5 months ago

Danke für die Info. Welche relevante Information soll ich dem asyncio Output entnehmen?

scharrrfi commented 5 months ago

Weiß ich nicht, ich wollte ihn nur nicht vorenthalten :) Vermutlich reicht der Output von hahomematic.platforms.entity, um auf Fehlersuche zu gehen. Scheint irgendwas hiermit zu tun zu haben: https://docs.python.org/3/library/asyncio-dev.html#concurrency-and-multithreading

Andere Custom-Integrationen sind wohl auch betroffen.

Wenn ihr weitere bzw. andere Logs braucht, sagt Bescheid.

SukramJ commented 5 months ago

Wie kann man das Problem reproduzieren?

scharrrfi commented 5 months ago

Relativ einfach: Profiler Integration hinzufügen und dann in den Entwicklereinstellungen den Dienst "Profiler: Asyncio-Debug einstellen" aktivieren. Ist auch in den verlinkten anderen Issues erläutert. Anschließend kommen schon die oben genannten Logeinträge.

Anscheinend gibt es pro Abruf einer Entität einen Log-Eintrag.

Das ursprüngliche Problem wurde vermutlich verursacht, weil hier die Temperatur eine HM-Entität sekündlich abgefragt wurde.

SukramJ commented 5 months ago

In der Version 1.59.0b0 (Beta) sollte das Problem behoben sein.

scharrrfi commented 5 months ago

Danke, scheint zu funktionieren!

danielperna84 / hahomematic