CPU usage is high after 2022.2.0

nao-pon commented 2 years ago

The problem

Until 2021.12.10, CPU usage was around 5% -9%. But with the same configuration, 2022.2.0 ~ 6 will be 15% ~ 20%. Downgrading to 2021.12.10 will reduce CPU usage.

What version of Home Assistant Core has the issue?

2022.2.0 ~ 2022.2.6

What was the last working version of Home Assistant Core?

2021.12.10

What type of installation are you running?

Home Assistant OS

Integration causing the issue

not clear

Link to integration documentation on our website

No response

Diagnostics information

I ran py-spy record. But I couldn't figure out the cause.

On 2021.12.10 -On 2022.2.6

Example YAML snippet

No response

Anything in the logs that might be useful for us?

No response

Additional information

System Health

version	core-2021.12.10
installation_type	Home Assistant OS
dev	false
hassio	true
docker	true
user	root
virtualenv	false
python_version	3.9.7
os_name	Linux
os_version	5.10.92-v7l
arch	armv7l
timezone	Asia/Tokyo

Home Assistant Community Store

Home Assistant Cloud

Home Assistant Supervisor

Lovelace

Integrations

mikeymikec commented 2 years ago

Try increasing the VM ram, worked for me

nao-pon commented 2 years ago

@mikeymikec Thank you for your reply! I'm running the Home Assistant OS on a Raspberry Pi4 2G and I'm not sure about VM RAM adjustments.

Until 2021.12.10, the CPU usage rate will increase to about 7%, and after 2022.2.0, it will increase to about 18%, and the CPU temperature will increase accordingly. Is Raspberry Pi4 2G inadequate to run after 2022.2.0?

I've guessed that some components are using a lot of CPU with the update, but can anyone solve this conundrum?

nao-pon commented 2 years ago

I tried 2022.2.7 but it didn't solve this problem.

Screenshot_20220216-221610_2

trippelb commented 2 years ago

I have te same issue

kernelpanic85 commented 2 years ago

I am having the same issue. CPU usage has increased after upgrade from 2021.12.10 to 2022.2.9. I don't see any glaring issues in the logs. This is on a Pi3B+ with HAOS 7.4.

I can see the following in top:

kernelpanic85 commented 2 years ago

Any hope of someone picking this up for the next release?

nao-pon commented 2 years ago

I have a similar problem with 2022.3.1. Naturally, the CPU temperature is also high. This issue can also be said to be a slowdown in Home Assistant Core performance since 2022.2.

FireShot Capture 006 - 管理者パネル - Home Assistant - hypha duckdns org

FireShot Capture 007 - 管理者パネル - Home Assistant - hypha duckdns org

signaleye commented 2 years ago

same issue with 2022.3.5. what could be the problem.. I have purge DB hoping. that. will fix but nothing disabled some. addons.... nothing..

alkissack commented 2 years ago

noticing high load here too core:2022.3.5 OS 7.5 on a VM. not sure on which release it started, but since Jan/Feb

nao-pon commented 2 years ago

Even core-2022.4.0 does not solve the problem of high CPU usage. Will it not return to the good condition until core-2021.12.10?

FireShot Capture 040 - 履歴 – Home Assistant - hypha duckdns org

TheDarthFather commented 2 years ago

I recently upgraded to core-2022.3.8 (Proxmox->VM->Docker) and I have the same problem. I am afraid I dont recall 100% .. but I belive it did not happen imediately after the upgrade ... it may be from an integration I updated later on. My entire server went to 7% from 3% and the HA doker is using 140% CPU instead of ~5% CPU.

Later Edit: I restored an older snapshot ... I am still on core-2022.3.8, but my CPU is under 2% again! So ... I assume one of those integrations made my CPU go so high. I will update 1 by 1 and validate later on ...

besiktas97 commented 2 years ago

I am having the same issue. Using HA on a rpi4 version 2022.4.5 with supervisor. Since the april update sky high cpu usage above 60%. Did anyone found the solution for this ?

kernelpanic85 commented 2 years ago

Update on this, I installed the Profiler integration and attached is the cprof graphic. Does this help anyone narrow it down?

output

bdraco commented 2 years ago

Please post py-spy recordings (120s) and callgrind.out files from the profiler integration.

py-spy instructions (but update python's version from 3.8 to 3.9 in the path of one of the commands.
Profiler integration

Thanks!

kernelpanic85 commented 2 years ago

Here is a zip of the callgrind and cprof files: Profiler.zip

My understanding is that I can't install py-spy on HassOS? I don't have the pip install command available.

bdraco commented 2 years ago

You need to do it in the homeassistant container. You can do it with the SSH & Web Terminal and turn off protected mode or

https://developers.home-assistant.io/docs/operating-system/debugging/

bdraco commented 2 years ago

eventloop

Nothing too interesting in the profile. denonavr and snmp using the most cpu time but still 92%+ idle

kernelpanic85 commented 2 years ago

Thank you, that worked! The SVG is in the zip:

py-spy.zip

bdraco commented 2 years ago

Well unfortunately that looks good so no issue there.

bdraco commented 2 years ago

What percent cpu is the process showing in top?

bdraco commented 2 years ago

The next step is to get an strace, but don't post it here because it can pickup sensitive data.

apk add strace strace -p <PID> -f -s4096 -o /config/ha.log

Let it run for ~120s and email to nick@koston.org a link / share

kernelpanic85 commented 2 years ago

Top on the host is usually around 80% (this is a Pi3B+)

Will share the strace directly

bdraco commented 2 years ago

Can you send a py-spy dump --pid 6042 as well so I can compare the process ids in the strace?

If the strace and the py-spy where taken between restarts, you'll need to do new ones. The dump should look like this

# py-spy  dump --pid 191
Process 191: python3 -m homeassistant --config /config
Python v3.9.7 (/usr/local/bin/python3.9)

Thread 191 (idle): "MainThread"
    select (selectors.py:469)
    _run_once (asyncio/base_events.py:1854)
    run_forever (asyncio/base_events.py:596)
    run_until_complete (asyncio/base_events.py:629)
    run (homeassistant/runner.py:119)
    main (homeassistant/__main__.py:191)
    <module> (homeassistant/__main__.py:203)
    _run_code (runpy.py:87)
    _run_module_as_main (runpy.py:197)
Thread 212 (idle): "Thread-1"
    dequeue (logging/handlers.py:1462)
    _monitor (logging/handlers.py:1513)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 213 (idle): "SyncWorker_0"
    _worker (concurrent/futures/thread.py:75)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 216 (idle): "SyncWorker_1"
    _worker (concurrent/futures/thread.py:75)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 217 (idle): "SyncWorker_2"
    _worker (concurrent/futures/thread.py:75)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 218 (idle): "SyncWorker_3"
    _worker (concurrent/futures/thread.py:75)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 219 (idle): "SyncWorker_4"
    _worker (concurrent/futures/thread.py:75)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 220 (idle): "SyncWorker_5"
    _worker (concurrent/futures/thread.py:75)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 221 (idle): "SyncWorker_6"
    _worker (concurrent/futures/thread.py:75)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 222 (idle): "SyncWorker_7"
    _worker (concurrent/futures/thread.py:75)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 223 (idle): "SyncWorker_8"
    _worker (concurrent/futures/thread.py:75)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 224 (idle): "Thread-2"
    dequeue (logging/handlers.py:1462)
    _monitor (logging/handlers.py:1513)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 225 (idle): "Recorder"
    _run_event_loop (homeassistant/components/recorder/core.py:569)
    run (homeassistant/components/recorder/core.py:560)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 227 (idle): "DbWorker_0"
    _worker (concurrent/futures/thread.py:75)
    _worker_with_shutdown_hook (homeassistant/components/recorder/executor.py:17)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 228 (idle): "DbWorker_1"
    _worker (concurrent/futures/thread.py:75)
    _worker_with_shutdown_hook (homeassistant/components/recorder/executor.py:17)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 229 (idle): "DbWorker_2"
    _worker (concurrent/futures/thread.py:75)
    _worker_with_shutdown_hook (homeassistant/components/recorder/executor.py:17)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 236 (idle): "Thread-3"
    _loop (paho/mqtt/client.py:1150)
    loop_forever (paho/mqtt/client.py:1756)
    _thread_main (paho/mqtt/client.py:3591)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 237 (idle): "SyncWorker_9"
    _worker (concurrent/futures/thread.py:75)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 238 (idle): "Thread-4"
    _loop (paho/mqtt/client.py:1150)
    loop_forever (paho/mqtt/client.py:1756)
    _thread_main (paho/mqtt/client.py:3591)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 239 (idle): "Thread-5"
    _loop (paho/mqtt/client.py:1150)
    loop_forever (paho/mqtt/client.py:1756)
    _thread_main (paho/mqtt/client.py:3591)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 241 (idle): "SyncWorker_10"
    _worker (concurrent/futures/thread.py:75)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 242 (idle): "SyncWorker_11"
    _worker (concurrent/futures/thread.py:75)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 243 (idle): "SyncWorker_12"
    _worker (concurrent/futures/thread.py:75)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 244 (idle): "SyncWorker_13"
    _worker (concurrent/futures/thread.py:75)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 245 (idle): "SyncWorker_14"
    _worker (concurrent/futures/thread.py:75)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 246 (idle): "SyncWorker_15"
    _worker (concurrent/futures/thread.py:75)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 247 (idle): "SyncWorker_16"
    _worker (concurrent/futures/thread.py:75)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 248 (idle): "SyncWorker_17"
    _worker (concurrent/futures/thread.py:75)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 249 (idle): "SyncWorker_18"
    _worker (concurrent/futures/thread.py:75)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 250 (idle): "SyncWorker_19"
    _worker (concurrent/futures/thread.py:75)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 251 (idle): "SyncWorker_20"
    _worker (concurrent/futures/thread.py:75)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 252 (idle): "SyncWorker_21"
    _worker (concurrent/futures/thread.py:75)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 253 (idle): "SyncWorker_22"
    _worker (concurrent/futures/thread.py:75)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 254 (idle): "SyncWorker_23"
    _worker (concurrent/futures/thread.py:75)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 255 (idle): "SyncWorker_24"
    _worker (concurrent/futures/thread.py:75)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 256 (idle): "SyncWorker_25"
    _worker (concurrent/futures/thread.py:75)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 257 (idle): "SyncWorker_26"
    _worker (concurrent/futures/thread.py:75)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 258 (idle): "SyncWorker_27"
    _worker (concurrent/futures/thread.py:75)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 259 (idle): "SyncWorker_28"
    _worker (concurrent/futures/thread.py:75)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 260 (idle): "SyncWorker_29"
    _worker (concurrent/futures/thread.py:75)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 261 (idle): "SyncWorker_30"
    _worker (concurrent/futures/thread.py:75)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 262 (idle): "SyncWorker_31"
    _worker (concurrent/futures/thread.py:75)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 263 (idle): "SyncWorker_32"
    _worker (concurrent/futures/thread.py:75)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 264 (idle): "DHCPWatcher"
    select (scapy/supersocket.py:259)
    _run (scapy/sendrecv.py:1175)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 266 (idle): "DbWorker_3"
    _worker (concurrent/futures/thread.py:75)
    _worker_with_shutdown_hook (homeassistant/components/recorder/executor.py:17)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)

kernelpanic85 commented 2 years ago

Sorry, the top I sent was from the host, not the homeassistant container. This is the top from homeassistant, not sure why the host is 80% but HA container runs around 20%, either way it is higher than it used to be before 2022.2.

Py-spy dump:

Process 192: python3 -m homeassistant --config /config
Python v3.9.9 (/usr/local/bin/python3.9)

Thread 0x76FE9020 (idle): "MainThread"
    select (selectors.py:469)
    _run_once (asyncio/base_events.py:1854)
    run_forever (asyncio/base_events.py:596)
    run_until_complete (asyncio/base_events.py:629)
    run (homeassistant/runner.py:119)
    main (homeassistant/__main__.py:191)
    <module> (homeassistant/__main__.py:203)
    _run_code (runpy.py:87)
    _run_module_as_main (runpy.py:197)
Thread 0x74709120 (active): "Thread-1"
    dequeue (logging/handlers.py:1473)
    _monitor (logging/handlers.py:1524)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 0x743BF120 (active): "SyncWorker_0"
    _worker (concurrent/futures/thread.py:81)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 0x73DF9120 (active): "SyncWorker_1"
    _worker (concurrent/futures/thread.py:81)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 0x739FF120 (active): "SyncWorker_2"
    _worker (concurrent/futures/thread.py:81)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 0x735FF120 (active): "SyncWorker_3"
    _worker (concurrent/futures/thread.py:81)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 0x731FF120 (active): "SyncWorker_4"
    _worker (concurrent/futures/thread.py:81)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 0x72DFF120 (active): "SyncWorker_5"
    _worker (concurrent/futures/thread.py:81)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 0x729FF120 (active): "SyncWorker_6"
    _worker (concurrent/futures/thread.py:81)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 0x725FF120 (active): "SyncWorker_7"
    _worker (concurrent/futures/thread.py:81)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 0x71E6F120 (active): "Recorder"
    _run_event_loop (homeassistant/components/recorder/__init__.py:928)
    run (homeassistant/components/recorder/__init__.py:919)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 0x71D2C120 (active): "Thread-2"
    dequeue (logging/handlers.py:1473)
    _monitor (logging/handlers.py:1524)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 0x6D36D120 (active): "SyncWorker_8"
    _worker (concurrent/futures/thread.py:81)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 0x6BDAB088 (active): "Thread-4"
    protected_loop_func (homeassistant/util/async_.py:174)
    run (tuya_iot/openmq.py:161)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 0x6A5EC088 (idle): "Thread-CallbackRequestDispatcher"
    wait (threading.py:312)
    get (queue.py:171)
    _get_many (pubsub_v1/subscriber/_protocol/helper_threads.py:56)
    __call__ (pubsub_v1/subscriber/_protocol/helper_threads.py:103)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 0x6A4A0088 (idle): "Thread-ConsumeBidirectionalStream"
    wait (threading.py:316)
    _wait_once (grpc/_common.py:106)
    wait (grpc/_common.py:141)
    _next (grpc/_channel.py:817)
    __next__ (grpc/_channel.py:426)
    __next__ (api_core/grpc_helpers.py:97)
    _recv (api_core/bidi.py:558)
    _recoverable (api_core/bidi.py:504)
    recv (api_core/bidi.py:561)
    _thread_main (api_core/bidi.py:655)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 0x6A389088 (idle): "Thread-LeaseMaintainer"
    wait (threading.py:316)
    wait (threading.py:574)
    maintain_leases (pubsub_v1/subscriber/_protocol/leaser.py:208)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 0x6A17D088 (idle): "Thread-Heartbeater"
    wait (threading.py:316)
    wait (threading.py:574)
    heartbeat (pubsub_v1/subscriber/_protocol/heartbeater.py:50)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 0x6A07A088 (active): "Thread-8"
    channel_spin (grpc/_channel.py:1258)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 0x69B32088 (active): "SyncWorker_9"
    _worker (concurrent/futures/thread.py:81)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 0x6502BE08 (active): "Thread-3"
    protected_loop_func (homeassistant/util/async_.py:174)
    run (raspihats/__init__.py:179)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 0x63C76C70 (active): "DHCPWatcher"
    select (scapy/supersocket.py:259)
    _run (scapy/sendrecv.py:1175)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 0x61444C70 (active): "ThreadPoolExecutor-ThreadScheduler_0"
    _worker (concurrent/futures/thread.py:81)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 0x5EBC6C70 (idle): "Thread-492"
    wait (threading.py:316)
    get (queue.py:180)
    __iter__ (api_core/bidi.py:109)
    consume_request_iterator (grpc/_channel.py:203)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)
Thread 0x5FF2DC70 (active): "Thread-493"
    _loop (paho/mqtt/client.py:1150)
    loop_forever (paho/mqtt/client.py:1756)
    _thread_main (paho/mqtt/client.py:3591)
    run (threading.py:910)
    _bootstrap_inner (threading.py:973)
    _bootstrap (threading.py:930)

New strace is incoming to your email

bdraco commented 2 years ago

6757  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76b0299e} ---
6757  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76b0298c} ---
6757  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76b02992} ---
6757  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76b02998} ---
6759  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76a9d99e} ---
6759  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76a9d98c} ---
6759  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76a9d992} ---
6759  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76a9d998} ---
6761  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76aec99e} ---
6761  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76aec98c} ---
6761  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76aec992} ---
6761  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76aec998} ---
6763  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76ae499e} ---
6763  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76ae498c} ---
6763  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76ae4992} ---
6763  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76ae4998} ---
6765  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76b0899e} ---
6765  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76b0898c} ---
6765  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76b08992} ---
6765  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76b08998} ---
6767  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76ade99e} ---
6767  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76ade98c} ---
6767  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76ade992} ---
6767  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76ade998} ---
6769  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76ae299e} ---
6769  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76ae298c} ---
6769  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76ae2992} ---
6769  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76ae2998} ---
6771  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76b3399e} ---
6771  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76b3398c} ---
6771  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76b33992} ---
6771  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76b33998} ---
6773  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76af699e} ---
6773  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76af698c} ---
6773  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76af6992} ---
6773  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76af6998} ---
6775  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76ad599e} ---
6775  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76ad598c} ---
6775  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76ad5992} ---
6775  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76ad5998} ---
6777  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76b0c99e} ---
6777  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76b0c98c} ---
6777  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76b0c992} ---
6777  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76b0c998} ---
6779  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76af199e} ---
6779  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76af198c} ---
6779  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76af1992} ---
6779  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76af1998} ---
6781  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76b5399e} ---
6781  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76b5398c} ---
6781  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76b53992} ---
6781  --- SIGILL {si_signo=SIGILL, si_code=ILL_ILLOPC, si_addr=0x76b53998} ---

SIGILL probably shouldn't be happening. Thats a bit unexpected.

bdraco commented 2 years ago

There is actually not that much going on in the strace. So its not an I/O issue or a syscall issue.

bdraco commented 2 years ago

I'm starting to think the problem is in native code. I don't think --native works with py-spy on an RPi3 though https://github.com/benfred/py-spy#can-py-spy-profile-native-extensions

kernelpanic85 commented 2 years ago

Thanks, I tried --native but it didn't work on dump or record. Anything else I can provide?

drking7 commented 2 years ago

I experienced the same high CPU issues as well. I am running a Supervised installation on a NUC I5. I noticed the same high CPU usage and tried isolating integrations and add-ons with no luck. So I downgraded from 2022.5.X to 2022.3.8 as TheDarthFather did. This solved my issue with the CPU usage going from around a constant 20% back to a normal value of around 2%.

bdraco commented 2 years ago

Thanks, I tried --native but it didn't work on dump or record. Anything else I can provide?

Honestly I'm out of ideas without direct access to the system.

bdraco commented 2 years ago

One more thing we can try, its a bit of a long shot but sometimes it pans out.

Try turning on full debug logging with

# Example configuration.yaml entry
logger:
  default: debug

Then email me a link to download to nick@koston.org

Don't post it here in the chance that something is logging something sensitive.

bdraco commented 2 years ago

@kernelpanic85 Its a bit of a longshot, but the only thing that looks like it might be cpu intensive is https://www.home-assistant.io/integrations/version/

Can you try disabling them ?

kernelpanic85 commented 2 years ago

@kernelpanic85 Its a bit of a longshot, but the only thing that looks like it might be cpu intensive is https://www.home-assistant.io/integrations/version/

Can you try disabling them ?

I actually uninstalled that a couple weeks ago after upgrading to 2022.4. Is there some remnants still there?

nao-pon commented 2 years ago

I'm using the latest Home Assistant Core to put up with the increased CPU usage. The graph below shows the characteristics of this problem since it was discovered. At some point, the lower limit of CPU usage will drop and the difference between the top and bottom will increase. If I continue to use it, the lower limit will gradually rise, and at some point the lower limit of CPU usage will drop. This situation does not occur before 2021.12.10. The integration I'm using remains the first post here. Many similar issues have been posted in this thread. Isn't it due to something that is always enabled, such as a logger, rather than a particular integration? FireShot Capture 042 - 履歴 – Home Assistant - hypha duckdns org

bdraco commented 2 years ago

@nao-pon The py-spys you posted in your opening text were compressed by github and all the timing data was lost. Can you upload a zip with them so github does not alter them.

nao-pon commented 2 years ago

pyspy.zip

It was a while ago. Output for 120 seconds with profiler integration. Is this okay?

bdraco commented 2 years ago

That zip file didn't have any svgs from py-spy but it did have a profiler callgrind

Here is what it looks like in qcachegrind

profile

bdraco commented 2 years ago

Looks like its camera related. Maybe more details with py-spy though.

nao-pon commented 2 years ago

I tried sampling for 120 seconds with py-spy.

py-spy-2022-5-4.zip

I finally get the following, do I need to lower the sampling rate?

508.54s behind in sampling, results may be inaccurate. Try reducing the sampling rate

bdraco commented 2 years ago

It looks like the snapshot wasn't too useful because it couldn't sample.

You could try decreasing the sampling rate to 50 and running it for longer.

nao-pon commented 2 years ago

@bdraco It is "-r 20 --duration 600"

result is "Wrote flamegraph data to '2022.5.4.svg'. Samples: 1056070 Errors: 41"

2022-5-4_r20_d600.zip

As for the camera, it doesn't seem to use much CPU.

nao-pon commented 2 years ago

@bdraco I did some sampling, but generally speaking, "_worker(concurrent/futures/thread.py: 75)" in 2021.12.10 is about 45%, while in 2022.2.0 and later, " _worker(concurrent/futures/thread.py: 81)"(line number 2022.5.5) is at least 70%. I don't know what this means.

bdraco commented 2 years ago

In 2022.5.5 is python 3.9 line 81 is https://github.com/python/cpython/blob/ab003d0ba485d6bce9b0b6736536e72e3e782c8d/Lib/concurrent/futures/thread.py#L81 Which is effectively wait until there is work to do which blocks and should take no (well almost imperceptible) cpu time

bdraco commented 2 years ago

Can you get a new py-spy with 2022.6 beta?

mvaneijken commented 2 years ago

In my case it had something to do with mDNS. I'm in the process of replacing my router and had two mDNS responders active in my network for a while. Thats something Home Assistant does not like. CPU levels are now as before. graph

nao-pon commented 2 years ago

Can you get a new py-spy with 2022.6 beta?

@bdraco Yes, However, there is no particular difference. CPU usage remains high.

2022-6-b3.zip

2022-6-b3

ThellraAK commented 2 years ago

You have 1.1.1.1:853 or 1.0.0.1:853 blocked?

was from me letting HA use it's own hardcoded DNS.

nao-pon commented 2 years ago

@ThellraAK I haven't explicitly blocked them. Is there anything I should allow?

ThellraAK commented 2 years ago

@nao-pon

Looks like you can turn off the fallback dns with

ha dns options --fallback=false into HA cli

It was suggested to check if things were going to break more from it to use

ha resolution info first though to see if everything was set up right.

I don't think you'd accidentally break DNS over TLS to open revolvers though, so this probably isn't your issue if it doesn't ring a bell already. (pfblockerng, pihole advanced setup, etc)

nao-pon commented 2 years ago

@ThellraAK Thanks!

I disabled the DNS fallback feature and restarted HA, but unfortunately the CPU usage did not drop much. The version of HA is 2022.7.4.

Home Assistant 2022.7.4 Supervisor 2022.07.0 Operating System 8.3 Front-end version: 20220707.0 --latest

I tried next commands.

➜  ~ ha resolution info
checks:
- enabled: true
  slug: supervisor_trust
- enabled: true
  slug: dns_server_ipv6_error
- enabled: true
  slug: addon_pwned
- enabled: true
  slug: free_space
- enabled: true
  slug: dns_server_failure
- enabled: true
  slug: core_security
issues: []
suggestions: []
unhealthy: []
unsupported: []
➜  ~ ha dns options --fallback=false
Command completed successfully.

home-assistant / core