core icon indicating copy to clipboard operation
core copied to clipboard

HA Core uses 100 % of the CPU

Open estebanz01 opened this issue 1 year ago • 14 comments

The problem

Since version 2024.06.4 and up to 2024.07.2, HA is using all the available CPU on my raspberry Pi and I can't pinpoint why is doing that. This didn't happen in 2024.5.5

What version of Home Assistant Core has the issue?

core-2024.7.2

What was the last working version of Home Assistant Core?

core-2024.5.5

What type of installation are you running?

Home Assistant Core

Integration causing the issue

No response

Link to integration documentation on our website

No response

Diagnostics information

System Information

version core-2024.7.2
installation_type Home Assistant Core
dev false
hassio false
docker false
user homeassistant
virtualenv true
python_version 3.12.2
os_name Linux
os_version 6.1.29-v8+
arch aarch64
timezone America/Bogota
config_dir /home/homeassistant/.homeassistant
Home Assistant Community Store
GitHub API ok
GitHub Content ok
GitHub Web ok
GitHub API Calls Remaining 5000
Installed Version 1.34.0
Stage running
Available Repositories 1385
Downloaded Repositories 4
Home Assistant Cloud
logged_in true
subscription_expiration 8 January 2025 at 19:00
relayer_connected true
relayer_region us-east-1
remote_enabled true
remote_connected true
alexa_enabled false
google_enabled true
remote_server us-east-1-0.ui.nabu.casa
certificate_status ready
instance_id ec70fa5f3e744848a672131e4f14a08f
can_reach_cert_server failed to load: timeout
can_reach_cloud_auth failed to load: timeout
can_reach_cloud ok
Dashboards
dashboards 6
resources 5
views 12
mode storage
Recorder
oldest_recorder_run 1 July 2024 at 14:36
current_recorder_run 10 July 2024 at 11:57
estimated_db_size 240.31 MiB
database_engine mysql
database_version 10.5.23

Example YAML snippet

No response

Anything in the logs that might be useful for us?

No response

Additional information

imagen

History for the CPU usage in the past 20 days. I updated from 2024.5.5 to 2024.6 on June 24th: imagen

estebanz01 avatar Jul 10 '24 20:07 estebanz01

Each drop to zero is me manually restarting the HA service, that's is needed due to the referenced issue ^

estebanz01 avatar Jul 10 '24 20:07 estebanz01

https://community.home-assistant.io/t/2024-5-tracking-down-instability-issues-caused-by-integrations/724441

Please see

Sluggish performance or increased CPU usage

bdraco avatar Jul 10 '24 20:07 bdraco

I don't see anything outstanding, tbh. Here's the valgrind file as it seems all calls are related to cookies and sessions. Is it because I have an open tab with a logged in user for the past 20 days? 😅 I just zipped the file so I can share it here, I didn't see anything sensitive on it.

callgrind.zip

estebanz01 avatar Jul 10 '24 21:07 estebanz01

Here's another one with 76 % CPU usage

callgrind.zip

estebanz01 avatar Jul 10 '24 22:07 estebanz01

The callgrinds look clean.

Maybe you can see something by attaching with strace

strace -p <PID> -f -s 4096 -o /config/strace.log

Note, strace will show all read and write calls so unlike the callgrinds which only show the function calls of the python code, its not safe to share publiclly.

bdraco avatar Jul 11 '24 01:07 bdraco

Is it possible you somehow have multiple copies of Home Assistant running at the same time?

bdraco avatar Jul 11 '24 12:07 bdraco

nope, only one running. I'll give it a go to strace and report what I get.

estebanz01 avatar Jul 11 '24 13:07 estebanz01

After running it while the CPU increases, I'm getting this message extremely loud in the output of strace:

[pid 1425921] futex(0x558beb2f60, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 0, NULL, FUTEX_BITSET_MATCH_ANY <unfinished ...>
[pid 1426430] pselect6(102, [101], [], NULL, {tv_sec=0, tv_nsec=0}, NULL) = 0 (Timeout)
[pid 1426430] pselect6(102, [101], [], NULL, {tv_sec=0, tv_nsec=0}, NULL) = 0 (Timeout)
[pid 1426430] pselect6(102, [101], [], NULL, {tv_sec=0, tv_nsec=0}, NULL) = 0 (Timeout)
[pid 1426430] pselect6(102, [101], [], NULL, {tv_sec=0, tv_nsec=0}, NULL) = 0 (Timeout)
[pid 1426430] pselect6(102, [101], [], NULL, {tv_sec=0, tv_nsec=0}, NULL) = 0 (Timeout)
[pid 1426430] pselect6(102, [101], [], NULL, {tv_sec=0, tv_nsec=0}, NULL) = 0 (Timeout)
[pid 1426430] pselect6(102, [101], [], NULL, {tv_sec=0, tv_nsec=0}, NULL) = 0 (Timeout)
[pid 1426430] pselect6(102, [101], [], NULL, {tv_sec=0, tv_nsec=0}, NULL) = 0 (Timeout)
[pid 1426430] pselect6(102, [101], [], NULL, {tv_sec=0, tv_nsec=0}, NULL) = 0 (Timeout)
[pid 1426430] pselect6(102, [101], [], NULL, {tv_sec=0, tv_nsec=0}, NULL) = 0 (Timeout)
[pid 1426430] pselect6(102, [101], [], NULL, {tv_sec=0, tv_nsec=0}, NULL) = 0 (Timeout)

From what I understand, something is waiting for a file descriptor to finish (docs of _pselect6_), which could be a TCP connection hanging, waiting for a response that never comes or a websocket connection.

I'm not well versed in this area, so don't hesitate to give material or ideas to research and understand better what's going on 😅

Now, pairing this info with what I have in the HA logs:

Jul 11 11:04:29 raspberrypi hass[1425896]: 2024-07-11 11:04:29.039 WARNING (MainThread) [custom_components.localtuya.common] [516...d42] Disconnected - waiting for discovery broadcast
Jul 11 11:04:30 raspberrypi hass[1425896]: 2024-07-11 11:04:30.639 WARNING (MainThread) [custom_components.localtuya.common] [eba...2wj] Disconnected - waiting for discovery broadcast
Jul 11 11:04:33 raspberrypi hass[1425896]: 2024-07-11 11:04:33.871 WARNING (MainThread) [custom_components.localtuya.common] [764...a45] Disconnected - waiting for discovery broadcast
Jul 11 11:04:43 raspberrypi hass[1425896]: 2024-07-11 11:04:43.732 WARNING (MainThread) [custom_components.localtuya.common] [764...0a6] Disconnected - waiting for discovery broadcast
Jul 11 11:04:45 raspberrypi hass[1425896]: 2024-07-11 11:04:45.723 ERROR (MainThread) [async_upnp_client.ssdp] Received error: [Errno 101] Network is unreachable, transport: <_SelectorDatagramTransport fd=76 read=polling write=<idle, bufsize=0>>, socket: <asyncio.TransportSocket fd=76, family=2, type=2, proto=0, laddr=('0.0.0.0', 42686)>
Jul 11 11:04:45 raspberrypi hass[1425896]: 2024-07-11 11:04:45.823 ERROR (MainThread) [async_upnp_client.ssdp] Received error: [Errno 99] Cannot assign requested address, transport: <_SelectorDatagramTransport fd=69 read=polling write=<idle, bufsize=0>>, socket: <asyncio.TransportSocket fd=69, family=10, type=2, proto=0, laddr=('::', 56783, 0, 0)>
Jul 11 11:04:48 raspberrypi hass[1425896]: 2024-07-11 11:04:48.210 WARNING (MainThread) [custom_components.localtuya.common] [516...d42] Failed to connect to 192.168.1.63: [Errno 101] Network is unreachable
Jul 11 11:04:49 raspberrypi hass[1425896]: 2024-07-11 11:04:49.427 WARNING (MainThread) [custom_components.localtuya.common] [764...a45] Disconnected - waiting for discovery broadcast
Jul 11 11:04:50 raspberrypi hass[1425896]: 2024-07-11 11:04:50.148 WARNING (MainThread) [custom_components.localtuya.common] [eba...2wj] Failed to connect to 192.168.1.17: [Errno 101] Network is unreachable
Jul 11 11:04:50 raspberrypi hass[1425896]: 2024-07-11 11:04:50.962 WARNING (MainThread) [custom_components.localtuya.common] [764...0a6] Failed to connect to 192.168.1.8: [Errno 101] Network is unreachable
Jul 11 11:04:53 raspberrypi hass[1425896]: 2024-07-11 11:04:53.154 WARNING (Thread-4) [pychromecast.socket_client] [Habitación Esteban(192.168.1.228):8009] Heartbeat timeout, resetting connection
Jul 11 11:04:53 raspberrypi hass[1425896]: 2024-07-11 11:04:53.190 WARNING (Thread-5) [pychromecast.socket_client] [Google home niños(192.168.1.209):8009] Heartbeat timeout, resetting connection
Jul 11 11:04:53 raspberrypi hass[1425896]: 2024-07-11 11:04:53.244 WARNING (Thread-6) [pychromecast.socket_client] [Sala display(192.168.1.26):8009] Heartbeat timeout, resetting connection
Jul 11 11:04:53 raspberrypi hass[1425896]: 2024-07-11 11:04:53.988 WARNING (Thread-7) [pychromecast.socket_client] [toda la casa(192.168.1.26):32029] Heartbeat timeout, resetting connection
Jul 11 11:04:54 raspberrypi hass[1425896]: 2024-07-11 11:04:54.196 WARNING (Thread-8) [pychromecast.socket_client] [Google Home(192.168.1.191):8009] Heartbeat timeout, resetting connection

It seems that when my Pi loses network connection, it fails to heal itself after the internet comes back 🤔 I don't think pychromecast or localtuya is the problem, it must be something on how the recovery is handled either on HA or python itself. Food for thought.

EDIT: Actually, I think it's healing properly, but not closing the stale connections, leading to sockets hanging and the process is unaware of them, leading to connection sockets that never gets closed/collected by garbage collector.

estebanz01 avatar Jul 11 '24 16:07 estebanz01

logged asynIO tasks into log.

ul 11 14:20:53 raspberrypi hass[1437486]: 2024-07-11 14:20:53.215 CRITICAL (MainThread) [homeassistant.components.profiler] Task: <Task pending name='Task-12125' coro=<ClientPeer._handler() running at /srv/homeassistant/lib/python3.12/site-packages/snitun/client/client_peer.py:139> wait_for=<Future pending cb=[shield.<locals>._outer_done_callback() at /usr/local/lib/python3.12/asyncio/tasks.py:922, Task.task_wakeup()]>>
Jul 11 14:20:53 raspberrypi hass[1437486]: 2024-07-11 14:20:53.216 CRITICAL (MainThread) [homeassistant.components.profiler] Task: <Task pending name='Task-14089' coro=<Connector.handler() running at /srv/homeassistant/lib/python3.12/site-packages/snitun/client/connector.py:87> wait_for=<Future pending cb=[Task.task_wakeup()]>>
Jul 11 14:20:53 raspberrypi hass[1437486]: 2024-07-11 14:20:53.216 CRITICAL (MainThread) [homeassistant.components.profiler] Task: <Task pending name='Task-12095' coro=<CloudGoogleConfig.async_report_state() running at /srv/homeassistant/lib/python3.12/site-packages/homeassistant/components/cloud/google_config.py:370> wait_for=<Future pending cb=[Task.task_wakeup()]> cb=[gather.<locals>._done_callback() at /usr/local/lib/python3.12/asyncio/tasks.py:767]>
Jul 11 14:20:53 raspberrypi hass[1437486]: 2024-07-11 14:20:53.216 CRITICAL (MainThread) [homeassistant.components.profiler] Task: <Task pending name='Task-1987' coro=<WebSocketHandler._writer() running at /srv/homeassistant/lib/python3.12/site-packages/homeassistant/components/websocket_api/http.py:144> wait_for=<Future pending cb=[Task.task_wakeup()]>>
Jul 11 14:20:53 raspberrypi hass[1437486]: 2024-07-11 14:20:53.216 CRITICAL (MainThread) [homeassistant.components.profiler] Task: <Task pending name='Task-79' coro=<BaseIoT.connect() running at /srv/homeassistant/lib/python3.12/site-packages/hass_nabucasa/iot_base.py:144> wait_for=<Future pending cb=[Task.task_wakeup()]>>
Jul 11 14:20:53 raspberrypi hass[1437486]: 2024-07-11 14:20:53.216 CRITICAL (MainThread) [homeassistant.components.profiler] Task: <Task pending name='Task-16361' coro=<_ScriptRun.async_run() running at /srv/homeassistant/lib/python3.12/site-packages/homeassistant/helpers/script.py:465>>
Jul 11 14:20:53 raspberrypi hass[1437486]: 2024-07-11 14:20:53.217 CRITICAL (MainThread) [homeassistant.components.profiler] Task: <Task pending name='Task-41' coro=<RequestHandler.start() running at /srv/homeassistant/lib/python3.12/site-packages/aiohttp/web_protocol.py:531> wait_for=<Task pending name='Task-42' coro=<RequestHandler._handle_request() running at /srv/homeassistant/lib/python3.12/site-packages/aiohttp/web_protocol.py:452> wait_for=<Future pending cb=[Task.task_wakeup()]> cb=[Task.task_wakeup()]>>
Jul 11 14:20:53 raspberrypi hass[1437486]: 2024-07-11 14:20:53.217 CRITICAL (MainThread) [homeassistant.components.profiler] Task: <Task pending name='websocket_api.async:handle_execute_script' coro=<_handle_async_response() running at /srv/homeassistant/lib/python3.12/site-packages/homeassistant/components/websocket_api/decorators.py:28>>
Jul 11 14:20:53 raspberrypi hass[1437486]: 2024-07-11 14:20:53.217 CRITICAL (MainThread) [homeassistant.components.profiler] Task: <Task pending name='Task-14104' coro=<RequestHandler._handle_request() running at /srv/homeassistant/lib/python3.12/site-packages/aiohttp/web_protocol.py:452> wait_for=<Future pending cb=[Task.task_wakeup()]> cb=[Task.task_wakeup()]>
Jul 11 14:20:53 raspberrypi hass[1437486]: 2024-07-11 14:20:53.217 CRITICAL (MainThread) [homeassistant.components.profiler] Task: <Task pending name='Task-15138' coro=<TuyaProtocol.start_heartbeat.<locals>.heartbeat_loop() running at /home/homeassistant/.homeassistant/custom_components/localtuya/pytuya/__init__.py:648> wait_for=<Future pending cb=[Task.task_wakeup()]>>
Jul 11 14:20:53 raspberrypi hass[1437486]: 2024-07-11 14:20:53.218 CRITICAL (MainThread) [homeassistant.components.profiler] Task: <Task pending name='Task-16362' coro=<ServiceRegistry.async_call() running at /srv/homeassistant/lib/python3.12/site-packages/homeassistant/core.py:2731>>
Jul 11 14:20:53 raspberrypi hass[1437486]: 2024-07-11 14:20:53.218 CRITICAL (MainThread) [homeassistant.components.profiler] Task: <Task pending name='Task-88' coro=<CognitoAuth._async_handle_token_refresh() running at /srv/homeassistant/lib/python3.12/site-packages/hass_nabucasa/auth.py:87> wait_for=<Future pending cb=[Task.task_wakeup()]>>
Jul 11 14:20:53 raspberrypi hass[1437486]: 2024-07-11 14:20:53.218 CRITICAL (MainThread) [homeassistant.components.profiler] Task: <Task pending name='Task-2044' coro=<BaseIoT.connect() running at /srv/homeassistant/lib/python3.12/site-packages/hass_nabucasa/iot_base.py:144> wait_for=<Future pending cb=[Task.task_wakeup()]>>
Jul 11 14:20:53 raspberrypi hass[1437486]: 2024-07-11 14:20:53.218 CRITICAL (MainThread) [homeassistant.components.profiler] Task: <Task pending name='Task-15140' coro=<TuyaProtocol.start_heartbeat.<locals>.heartbeat_loop() running at /home/homeassistant/.homeassistant/custom_components/localtuya/pytuya/__init__.py:648> wait_for=<Future pending cb=[Task.task_wakeup()]>>
Jul 11 14:20:53 raspberrypi hass[1437486]: 2024-07-11 14:20:53.218 CRITICAL (MainThread) [homeassistant.components.profiler] Task: <Task pending name='Task-80' coro=<RemoteUI._certificate_handler() running at /srv/homeassistant/lib/python3.12/site-packages/hass_nabucasa/remote.py:510> wait_for=<Future pending cb=[Task.task_wakeup()]>>
Jul 11 14:20:53 raspberrypi hass[1437486]: 2024-07-11 14:20:53.218 CRITICAL (MainThread) [homeassistant.components.profiler] Task: <Task pending name='Task-12094' coro=<async_enable_report_state.<locals>.report_states() running at /srv/homeassistant/lib/python3.12/site-packages/homeassistant/components/google_assistant/report_state.py:58> wait_for=<_GatheringFuture pending cb=[Task.task_wakeup()]> cb=[set.remove()]>
Jul 11 14:20:53 raspberrypi hass[1437486]: 2024-07-11 14:20:53.219 CRITICAL (MainThread) [homeassistant.components.profiler] Task: <Task pending name='Task-16324' coro=<_ScriptRun.async_run() running at /srv/homeassistant/lib/python3.12/site-packages/homeassistant/helpers/script.py:465> wait_for=<Future pending cb=[Task.task_wakeup()]> cb=[shield.<locals>._inner_done_callback() at /usr/local/lib/python3.12/asyncio/tasks.py:905]>
Jul 11 14:20:53 raspberrypi hass[1437486]: 2024-07-11 14:20:53.219 CRITICAL (MainThread) [homeassistant.components.profiler] Task: <Task pending name="state trigger {'domain': 'automation', 'name': 'Kids Bathroom light timer', 'home_assistant_start': True, 'variables': {'this': {'entity_id': 'automation.hola', 'state': 'on', 'attributes': {'id': '1709925726387', 'last_triggered': datetime.datetime(2024, 7, 11, 15, 10, 6, 27095, tzinfo=datetime.timezone.utc), 'mode': 'restart', 'current': 0, 'friendly_name': 'Kids Bathroom light timer'}, 'last_changed': '2024-07-11T16:58:52.467114+00:00', 'last_reported': '2024-07-11T16:58:52.467114+00:00', 'last_updated': '2024-07-11T16:58:52.467114+00:00', 'context': {'id': '01J2HBQGNKYV7G36EJYYZ7C9ME', 'parent_id': None, 'user_id': None}}}, 'trigger_data': {'id': '0', 'idx': '0', 'alias': None}}" coro=<AutomationEntity._async_trigger_if_enabled() running at /srv/homeassistant/lib/python3.12/site-packages/homeassistant/components/automation/__init__.py:858> wait_for=<Future pending cb=[shield.<locals>._outer_done_callback() at /usr/local/lib/python3.12/asyncio/tasks.py:922, Task.task_wakeup()]> cb=[set.remove()]>
Jul 11 14:20:53 raspberrypi hass[1437486]: 2024-07-11 14:20:53.219 CRITICAL (MainThread) [homeassistant.components.profiler] Task: <Task pending name='Task-1495' coro=<RemoteUI._reconnect_snitun() running at /srv/homeassistant/lib/python3.12/site-packages/hass_nabucasa/remote.py:493> wait_for=<Future pending cb=[shield.<locals>._outer_done_callback() at /usr/local/lib/python3.12/asyncio/tasks.py:922, Task.task_wakeup()]>>
Jul 11 14:20:53 raspberrypi hass[1437486]: 2024-07-11 14:20:53.219 CRITICAL (MainThread) [homeassistant.components.profiler] Task: <Task pending name='Task-13827' coro=<GoogleReportState._async_message_sender() running at /srv/homeassistant/lib/python3.12/site-packages/hass_nabucasa/google_report_state.py:117> wait_for=<Future pending cb=[Task.task_wakeup()]>>
Jul 11 14:20:53 raspberrypi hass[1437486]: 2024-07-11 14:20:53.220 CRITICAL (MainThread) [homeassistant.components.profiler] Task: <Task pending name='Task-16323' coro=<Script.async_run() running at /srv/homeassistant/lib/python3.12/site-packages/homeassistant/helpers/script.py:1770> wait_for=<Future pending cb=[shield.<locals>._outer_done_callback() at /usr/local/lib/python3.12/asyncio/tasks.py:922, Task.task_wakeup()]> cb=[set.remove(), Task.task_wakeup()]>
Jul 11 14:20:53 raspberrypi hass[1437486]: 2024-07-11 14:20:53.220 CRITICAL (MainThread) [homeassistant.components.profiler] Task: <Task pending name='Task-1543' coro=<WebSocketClient._process_messages() running at /home/homeassistant/.homeassistant/custom_components/eufy_security/eufy_security_api/web_socket_client.py:63> wait_for=<Future pending cb=[Task.task_wakeup()]> cb=[WebSocketClient._on_close()]>
Jul 11 14:20:53 raspberrypi hass[1437486]: 2024-07-11 14:20:53.220 CRITICAL (MainThread) [homeassistant.components.profiler] Task: <Task pending name='Task-14941' coro=<RequestHandler.start() running at /srv/homeassistant/lib/python3.12/site-packages/aiohttp/web_protocol.py:531> wait_for=<Task pending name='Task-14943' coro=<RequestHandler._handle_request() running at /srv/homeassistant/lib/python3.12/site-packages/aiohttp/web_protocol.py:452> cb=[Task.task_wakeup()]>>
Jul 11 14:20:53 raspberrypi hass[1437486]: 2024-07-11 14:20:53.220 CRITICAL (MainThread) [homeassistant.components.profiler] Task: <Task pending name='Task-1' coro=<setup_and_run_hass() running at /srv/homeassistant/lib/python3.12/site-packages/homeassistant/runner.py:166> wait_for=<Future pending cb=[Task.task_wakeup()]> cb=[_run_until_complete_cb() at /usr/local/lib/python3.12/asyncio/base_events.py:181]>
Jul 11 14:20:53 raspberrypi hass[1437486]: 2024-07-11 14:20:53.220 CRITICAL (MainThread) [homeassistant.components.profiler] Task: <Task pending name='Task-16268' coro=<StreamReader.read() running at /usr/local/lib/python3.12/asyncio/streams.py:713> wait_for=<Future pending cb=[Task.task_wakeup()]> cb=[_wait.<locals>._on_completion() at /usr/local/lib/python3.12/asyncio/tasks.py:534]>
Jul 11 14:20:53 raspberrypi hass[1437486]: 2024-07-11 14:20:53.227 CRITICAL (MainThread) [homeassistant.components.profiler] Task: <Task pending name='Task-14945' coro=<WebSocketHandler._writer() running at /srv/homeassistant/lib/python3.12/site-packages/homeassistant/components/websocket_api/http.py:144> wait_for=<Future pending cb=[Task.task_wakeup()]>>
Jul 11 14:20:53 raspberrypi hass[1437486]: 2024-07-11 14:20:53.227 CRITICAL (MainThread) [homeassistant.components.profiler] Task: <Task pending name='Task-1983' coro=<RequestHandler._handle_request() running at /srv/homeassistant/lib/python3.12/site-packages/aiohttp/web_protocol.py:452> wait_for=<Future pending cb=[Task.task_wakeup()]> cb=[Task.task_wakeup()]>
Jul 11 14:20:53 raspberrypi hass[1437486]: 2024-07-11 14:20:53.228 CRITICAL (MainThread) [homeassistant.components.profiler] Task: <Task pending name='Task-16266' coro=<MultiplexerChannel.read() running at /srv/homeassistant/lib/python3.12/site-packages/snitun/multiplexer/channel.py:96> wait_for=<Future pending cb=[Task.task_wakeup()]> cb=[_wait.<locals>._on_completion() at /usr/local/lib/python3.12/asyncio/tasks.py:534]>
Jul 11 14:20:53 raspberrypi hass[1437486]: 2024-07-11 14:20:53.228 CRITICAL (MainThread) [homeassistant.components.profiler] Task: <Task pending name='Task-12124' coro=<Multiplexer._runner() running at /srv/homeassistant/lib/python3.12/site-packages/snitun/multiplexer/core.py:136> wait_for=<Future pending cb=[Task.task_wakeup()]> cb=[shield.<locals>._inner_done_callback() at /usr/local/lib/python3.12/asyncio/tasks.py:905, shield.<locals>._inner_done_callback() at /usr/local/lib/python3.12/asyncio/tasks.py:905]>
Jul 11 14:20:53 raspberrypi hass[1437486]: 2024-07-11 14:20:53.228 CRITICAL (MainThread) [homeassistant.components.profiler] Task: <Task pending name='Task-15137' coro=<TuyaProtocol.start_heartbeat.<locals>.heartbeat_loop() running at /home/homeassistant/.homeassistant/custom_components/localtuya/pytuya/__init__.py:648> wait_for=<Future pending cb=[Task.task_wakeup()]>>
Jul 11 14:20:53 raspberrypi hass[1437486]: 2024-07-11 14:20:53.228 CRITICAL (MainThread) [homeassistant.components.profiler] Task: <Task pending name='Task-16331' coro=<StreamReader.readexactly() running at /usr/local/lib/python3.12/asyncio/streams.py:752> wait_for=<Future pending cb=[Task.task_wakeup()]> cb=[_wait.<locals>._on_completion() at /usr/local/lib/python3.12/asyncio/tasks.py:534]>
Jul 11 14:20:53 raspberrypi hass[1437486]: 2024-07-11 14:20:53.229 CRITICAL (MainThread) [homeassistant.components.profiler] Task: <Task pending name='Task-1982' coro=<RequestHandler.start() running at /srv/homeassistant/lib/python3.12/site-packages/aiohttp/web_protocol.py:531> wait_for=<Task pending name='Task-1983' coro=<RequestHandler._handle_request() running at /srv/homeassistant/lib/python3.12/site-packages/aiohttp/web_protocol.py:452> wait_for=<Future pending cb=[Task.task_wakeup()]> cb=[Task.task_wakeup()]>>
Jul 11 14:20:53 raspberrypi hass[1437486]: 2024-07-11 14:20:53.229 CRITICAL (MainThread) [homeassistant.components.profiler] Task: <Task pending name='Task-14109' coro=<WebSocketHandler._writer() running at /srv/homeassistant/lib/python3.12/site-packages/homeassistant/components/websocket_api/http.py:144> wait_for=<Future pending cb=[Task.task_wakeup()]>>
Jul 11 14:20:53 raspberrypi hass[1437486]: 2024-07-11 14:20:53.229 CRITICAL (MainThread) [homeassistant.components.profiler] Task: <Task pending name='Task-16269' coro=<Queue.get() running at /usr/local/lib/python3.12/asyncio/queues.py:158> wait_for=<Future pending cb=[Task.task_wakeup()]> cb=[_wait.<locals>._on_completion() at /usr/local/lib/python3.12/asyncio/tasks.py:534]>
Jul 11 14:20:53 raspberrypi hass[1437486]: 2024-07-11 14:20:53.229 CRITICAL (MainThread) [homeassistant.components.profiler] Task: <Task pending name='Task-14099' coro=<RequestHandler.start() running at /srv/homeassistant/lib/python3.12/site-packages/aiohttp/web_protocol.py:531> wait_for=<Task pending name='Task-14104' coro=<RequestHandler._handle_request() running at /srv/homeassistant/lib/python3.12/site-packages/aiohttp/web_protocol.py:452> wait_for=<Future pending cb=[Task.task_wakeup()]> cb=[Task.task_wakeup()]>>
Jul 11 14:20:53 raspberrypi hass[1437486]: 2024-07-11 14:20:53.229 CRITICAL (MainThread) [homeassistant.components.profiler] Task: <Task pending name='Task-14598' coro=<Script.async_run() running at /srv/homeassistant/lib/python3.12/site-packages/homeassistant/helpers/script.py:1770> wait_for=<Future pending cb=[shield.<locals>._outer_done_callback() at /usr/local/lib/python3.12/asyncio/tasks.py:922, Task.task_wakeup()]> cb=[set.remove(), Task.task_wakeup()]>
Jul 11 14:20:53 raspberrypi hass[1437486]: 2024-07-11 14:20:53.230 CRITICAL (MainThread) [homeassistant.components.profiler] Task: <Task pending name='Task-14943' coro=<RequestHandler._handle_request() running at /srv/homeassistant/lib/python3.12/site-packages/aiohttp/web_protocol.py:452> cb=[Task.task_wakeup()]>
Jul 11 14:20:53 raspberrypi hass[1437486]: 2024-07-11 14:20:53.230 CRITICAL (MainThread) [homeassistant.components.profiler] Task: <Task pending name='Task-15139' coro=<TuyaProtocol.start_heartbeat.<locals>.heartbeat_loop() running at /home/homeassistant/.homeassistant/custom_components/localtuya/pytuya/__init__.py:648> wait_for=<Future pending cb=[Task.task_wakeup()]>>
Jul 11 14:20:53 raspberrypi hass[1437486]: 2024-07-11 14:20:53.230 CRITICAL (MainThread) [homeassistant.components.profiler] Task: <Task pending name='Task-43' coro=<WebSocketHandler._writer() running at /srv/homeassistant/lib/python3.12/site-packages/homeassistant/components/websocket_api/http.py:144> wait_for=<Future pending cb=[Task.task_wakeup()]>>
Jul 11 14:20:53 raspberrypi hass[1437486]: 2024-07-11 14:20:53.230 CRITICAL (MainThread) [homeassistant.components.profiler] Task: <Task pending name='admin service profiler.log_current_tasks' coro=<async_setup_entry.<locals>._async_dump_current_tasks() running at /srv/homeassistant/lib/python3.12/site-packages/homeassistant/components/profiler/__init__.py:253>>
Jul 11 14:20:53 raspberrypi hass[1437486]: 2024-07-11 14:20:53.230 CRITICAL (MainThread) [homeassistant.components.profiler] Task: <Task pending name='Task-14583' coro=<_ScriptRun.async_run() running at /srv/homeassistant/lib/python3.12/site-packages/homeassistant/helpers/script.py:465> wait_for=<Task pending name='Task-14598' coro=<Script.async_run() running at /srv/homeassistant/lib/python3.12/site-packages/homeassistant/helpers/script.py:1770> wait_for=<Future pending cb=[shield.<locals>._outer_done_callback() at /usr/local/lib/python3.12/asyncio/tasks.py:922, Task.task_wakeup()]> cb=[set.remove(), Task.task_wakeup()]> cb=[shield.<locals>._inner_done_callback() at /usr/local/lib/python3.12/asyncio/tasks.py:905]>
Jul 11 14:20:53 raspberrypi hass[1437486]: 2024-07-11 14:20:53.231 CRITICAL (MainThread) [homeassistant.components.profiler] Task: <Task pending name='Task-42' coro=<RequestHandler._handle_request() running at /srv/homeassistant/lib/python3.12/site-packages/aiohttp/web_protocol.py:452> wait_for=<Future pending cb=[Task.task_wakeup()]> cb=[Task.task_wakeup()]>
Jul 11 14:20:53 raspberrypi hass[1437486]: 2024-07-11 14:20:53.231 CRITICAL (MainThread) [homeassistant.components.profiler] Task: <Task pending name='Task-14599' coro=<_ScriptRun.async_run() running at /srv/homeassistant/lib/python3.12/site-packages/homeassistant/helpers/script.py:465> wait_for=<Task pending name='Task-16323' coro=<Script.async_run() running at /srv/homeassistant/lib/python3.12/site-packages/homeassistant/helpers/script.py:1770> wait_for=<Future pending cb=[shield.<locals>._outer_done_callback() at /usr/local/lib/python3.12/asyncio/tasks.py:922, Task.task_wakeup()]> cb=[set.remove(), Task.task_wakeup()]> cb=[shield.<locals>._inner_done_callback() at /usr/local/lib/python3.12/asyncio/tasks.py:905]>

the only suspicious-looking for me are:

Jul 11 14:20:53 raspberrypi hass[1437486]: 2024-07-11 14:20:53.219 CRITICAL (MainThread) [homeassistant.components.profiler] Task: <Task pending name='Task-1495' coro=<RemoteUI._reconnect_snitun() running at /srv/homeassistant/lib/python3.12/site-packages/hass_nabucasa/remote.py:493> wait_for=<Future pending cb=[shield.<locals>._outer_done_callback() at /usr/local/lib/python3.12/asyncio/tasks.py:922, Task.task_wakeup()]>>
Jul 11 14:20:53 raspberrypi hass[1437486]: 2024-07-11 14:20:53.219 CRITICAL (MainThread) [homeassistant.components.profiler] Task: <Task pending name='Task-13827' coro=<GoogleReportState._async_message_sender() running at /srv/homeassistant/lib/python3.12/site-packages/hass_nabucasa/google_report_state.py:117> wait_for=<Future pending cb=[Task.task_wakeup()]>>
Jul 11 14:20:53 raspberrypi hass[1437486]: 2024-07-11 14:20:53.228 CRITICAL (MainThread) [homeassistant.components.profiler] Task: <Task pending name='Task-15137' coro=<TuyaProtocol.start_heartbeat.<locals>.heartbeat_loop() running at /home/homeassistant/.homeassistant/custom_components/localtuya/pytuya/__init__.py:648> wait_for=<Future pending cb=[Task.task_wakeup()]>>

but in reality, I don't see anything weird.

estebanz01 avatar Jul 11 '24 19:07 estebanz01

I think I found the integration causing the problem: iperf3. I had it disabled it for 24h and I didn't see a spike in CPU, but after enabled it again, the CPU spikes began. I enabled it after I did the upgrade from 2024.5.5, which correlates with the sudden CPU behaviour.

I'm wondering if that's the root cause of #121084

estebanz01 avatar Jul 14 '24 00:07 estebanz01

Here's an image showing the time iperf3 integration was disabled and enabled in a 24h period:

imagen

estebanz01 avatar Jul 14 '24 00:07 estebanz01

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

Code owner commands

Code owners of iperf3 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 iperf3 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)


iperf3 documentation iperf3 source (message by IssueLinks)

home-assistant[bot] avatar Jul 14 '24 00:07 home-assistant[bot]

here's my configuration:

# iperf3 integration - Speed test.
iperf3:
  hosts:
    - host: speedtest.masnet.ec # Ecuador (Santa Ana)
      port: 5201
    - host: speedtest.wtnet.de # Germany (Norderstedt)
      port: 5200
    - host: speedtest.mia11.us.leaseweb.net # US (MIA)
      port: 5201

estebanz01 avatar Jul 15 '24 20:07 estebanz01

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.

this is still happening, but it seems there's no acknowledge from the iperf maintainers.

estebanz01 avatar Oct 21 '24 14:10 estebanz01

I'm observing the same behaviour with multiple hosts specified. Single host works fine though.

voron avatar Oct 28 '24 04:10 voron

I have issues with iperf3 in HA since long time ago https://github.com/home-assistant/core/issues/110538#issuecomment-1956760147 I was able to pinpoint to iperf3 core integration having some issues when running. https://stackoverflow.com/questions/44519799/running-iperf-server-and-client-using-multithreading-in-python-causes-segmentati

multiple hosts specified

That might seem the issue indeed. My config (which i had to disable as it would crash my system, both an Rpi4 and Intel N150 running HAOS).

iperf3:
  monitored_conditions:
    - upload
    - download
  scan_interval: "04:07" #'HH:MM' or 'HH:MM:SS'
  hosts:
    - host: paris.testdebit.info
      port: 9221
      parallel: 2 
      duration: 10
    - host: ping.online.net
      port: 5209
      parallel: 2 
      duration: 9

Everytime it reaches that 4hrs 7 minutes HA core would crash.

diamant-x avatar Apr 25 '25 09:04 diamant-x

I tested it this week a couple of times with the most simple approach I could setup which is:

iperf3:
  monitored_conditions:
    - upload
    - download
  hosts:
    - host: paris.testdebit.info
      port: 9221
      parallel: 1
      duration: 10

And the moment I trigger the iperf service to run against paris.testdebit.info HA core would crash. So from my experience the iperf3 integration is broken. Based on analytics there's only 173 of us who uses/tries to use it https://analytics.home-assistant.io/integrations/ but woudl be nice to at least know if the issue is global and acknowledge @rohankapoorcom or someone has a working iperf3 config against a public server?

diamant-x avatar May 08 '25 12:05 diamant-x

I just setup this integration and, for me at least, it's working perfectly from the start so it's not a global issue. I also haven't been able to replicate the issue, even with multiple hosts.

Running HAOS in a Proxmox VM.

iperf3:
  monitored_conditions:
    - download
    - upload
  hosts:
    - host: speedtest.syd12.au.leaseweb.net
      port: 5201
  scan_interval:
    days: 0
    hours: 1
    minutes: 0
    seconds: 0
    milliseconds: 0

Dreytac avatar Sep 18 '25 18:09 Dreytac