How to install Py spy on a HA OS instance, please instruct

It’s pretty clear that you are hitting the limits of the cpu or I/O here since startup is a race to get in line and doesn’t always happen in the same order. When the system can no longer keep up, whichever integration is in line gets the higher numbers (although the ones with the large numbers are likely a problem themselves) because they are waiting for the other integrations that are consuming all the resources.

Improving that doesn’t have a magic bullet fix because you have to work on making everything that’s in line more efficient. The solution to these type of issues is usually a combination of many changes as we identify areas that are resource hungry or inefficient based on logs and py-spys etc. The process goes a lot faster if it’s something we can replicate locally, but if I could, it would have already taken care of it :wink:

Improving this is going to come down to lots and lots of py-spy’s and profiles at startup time (and maybe even instrumenting your instance with cProfile at startup time), along with some luck that we catch it at the right time.

Also the yaml loading speed up change likely isn’t effective yet since we haven’t rebuilt the wheels yet which it needs to see the performance improvement

Af that might explain the changing results. The first (better) result in the helpers was a fluke :wink: or plain variation …

As for the Py spy: I truly want to but am still trying to figure out how .

Anyways: I think it it safe to assume the Mqtt is top of the list. And trickling down too because many of the others are depending on the sensors it creates.
It would be a great start for more efficiency if possible

I just checked upon the last restart and it has grown to a horrifying:

which is beyond anything Ive ever seen. The dedicated add-on HA instance is running 2022.6.5 now, but I doubt that causes issues. it has very decent startup times, and its a RPi3:

the production instance is running latest dev ( I know, I know), and sees increasing startup times in this cycle unfortunately. Only thing in MQTT I changed is the new syntax to mqtt: .

And, last 3 days, I have moved almost all helpers from yaml to UI… hoping things would get better :wink:

given the frontend errors I get during startup (can not read the templates in custom:button-card), the UI helper groups are most questionable. Never noticed these template errors popup, and now they remain in the dashboard until completely started.

Other than that, I cant imagine what could have caused this.

edit

also noticed my Processor % is up to ca 13%, where it was circling 10% before.

still nothing to worry about, just saying it increased significantly

and confirming my suspicion on the helpers, platform group:

2022-06-15 08:56:32 WARNING (MainThread) [homeassistant.components.light] Setup of light platform group is taking over 10 seconds.
2022-06-15 08:56:32 WARNING (MainThread) [homeassistant.components.light] Setup of light platform group is taking over 10 seconds.
2022-06-15 08:56:32 WARNING (MainThread) [homeassistant.components.light] Setup of light platform group is taking over 10 seconds.
2022-06-15 08:56:32 WARNING (MainThread) [homeassistant.components.light] Setup of light platform group is taking over 10 seconds.
2022-06-15 08:56:32 WARNING (MainThread) [homeassistant.components.light] Setup of light platform group is taking over 10 seconds.
2022-06-15 08:56:32 WARNING (MainThread) [homeassistant.components.light] Setup of light platform group is taking over 10 seconds.
2022-06-15 08:56:32 WARNING (MainThread) [homeassistant.components.light] Setup of light platform group is taking over 10 seconds.
2022-06-15 08:56:32 WARNING (MainThread) [homeassistant.components.light] Setup of light platform group is taking over 10 seconds.
2022-06-15 08:56:32 WARNING (MainThread) [homeassistant.components.light] Setup of light platform group is taking over 10 seconds.
2022-06-15 08:56:32 WARNING (MainThread) [homeassistant.components.light] Setup of light platform group is taking over 10 seconds.
2022-06-15 08:56:32 WARNING (MainThread) [homeassistant.components.light] Setup of light platform group is taking over 10 seconds.
2022-06-15 08:56:32 WARNING (MainThread) [homeassistant.components.light] Setup of light platform group is taking over 10 seconds.
2022-06-15 08:56:32 WARNING (MainThread) [homeassistant.components.light] Setup of light platform group is taking over 10 seconds.
2022-06-15 08:56:32 WARNING (MainThread) [homeassistant.components.light] Setup of light platform group is taking over 10 seconds.
2022-06-15 08:56:32 WARNING (MainThread) [homeassistant.components.light] Setup of light platform group is taking over 10 seconds.
2022-06-15 08:56:32 WARNING (MainThread) [homeassistant.components.light] Setup of light platform group is taking over 10 seconds.
2022-06-15 08:56:32 WARNING (MainThread) [homeassistant.components.binary_sensor] Setup of binary_sensor platform group is taking over 10 seconds.
2022-06-15 08:56:32 WARNING (MainThread) [homeassistant.components.binary_sensor] Setup of binary_sensor platform group is taking over 10 seconds.
2022-06-15 08:56:32 WARNING (MainThread) [homeassistant.components.cover] Setup of cover platform group is taking over 10 seconds.
2022-06-15 08:56:32 WARNING (MainThread) [homeassistant.components.cover] Setup of cover platform group is taking over 10 seconds.
2022-06-15 08:56:32 WARNING (MainThread) [homeassistant.components.cover] Setup of cover platform group is taking over 10 seconds.
2022-06-15 08:56:32 WARNING (MainThread) [homeassistant.components.cover] Setup of cover platform group is taking over 10 seconds.
2022-06-15 08:56:32 WARNING (MainThread) [homeassistant.components.binary_sensor] Setup of binary_sensor platform group is taking over 10 seconds.
2022-06-15 08:56:32 WARNING (MainThread) [homeassistant.components.binary_sensor] Setup of binary_sensor platform group is taking over 10 seconds.
2022-06-15 08:56:32 WARNING (MainThread) [homeassistant.components.binary_sensor] Setup of binary_sensor platform group is taking over 10 seconds.
2022-06-15 08:56:32 WARNING (MainThread) [homeassistant.components.binary_sensor] Setup of binary_sensor platform group is taking over 10 seconds.
2022-06-15 08:56:32 WARNING (MainThread) [homeassistant.components.binary_sensor] Setup of binary_sensor platform group is taking over 10 seconds.
2022-06-15 08:56:32 WARNING (MainThread) [homeassistant.components.binary_sensor] Setup of binary_sensor platform group is taking over 10 seconds.
2022-06-15 08:56:32 WARNING (MainThread) [homeassistant.components.light] Setup of light platform group is taking over 10 seconds.
2022-06-15 08:56:32 WARNING (MainThread) [homeassistant.components.light] Setup of light platform group is taking over 10 seconds.
2022-06-15 08:56:32 WARNING (MainThread) [homeassistant.components.binary_sensor] Setup of binary_sensor platform group is taking over 10 seconds.
2022-06-15 08:56:32 WARNING (MainThread) [homeassistant.components.binary_sensor] Setup of binary_sensor platform group is taking over 10 seconds.
2022-06-15 08:56:32 WARNING (MainThread) [homeassistant.components.binary_sensor] Setup of binary_sensor platform group is taking over 10 seconds.
2022-06-15 08:56:32 WARNING (MainThread) [homeassistant.components.binary_sensor] Setup of binary_sensor platform group is taking over 10 seconds.
2022-06-15 08:56:32 WARNING (MainThread) [homeassistant.components.binary_sensor] Setup of binary_sensor platform group is taking over 10 seconds.
2022-06-15 08:56:32 WARNING (MainThread) [homeassistant.components.binary_sensor] Setup of binary_sensor platform group is taking over 10 seconds.
2022-06-15 08:56:32 WARNING (MainThread) [homeassistant.components.binary_sensor] Setup of binary_sensor platform group is taking over 10 seconds.
2022-06-15 08:56:32 WARNING (MainThread) [homeassistant.components.binary_sensor] Setup of binary_sensor platform group is taking over 10 seconds.

Ill file that as a separate issue, might be on to something here

This PR should help quite a bit as there is a lot of JSON overhead in your profiles

great!
form the user perspective: how can I prevent that JSON overhead? (exactly what is that actually?) caused by an integration, or frontend, where do I look for improving my config to prevent that from happening.

in the PR you mention:

Every UI that pulls significant data from the websocket is noticeably snappier with orjson .

so I guess it is frontend being heavy? If that is tackled by this, am puzzled how that would influence the startup times of integrations, which are all backend.

As I mentioned in DM, closing the Frontend on a restart does make a huge difference for the startup time of the instance and can be tracked in the homeassistant.log , but it doesnt really change the list of the Integrations startup time in System Health.

Nearly everything in .storage is a JSON document. A faster JSON parser mean everything that reads or writes JSON data takes less time. If an integrations needs data that was stored there it has to wait for the JSON to be read from disk and converted to python internals.

Nearly everything that communicates from core to the frontend does so with JSON over the websocket. Since everything has to be converted from python’s internals to JSON so the frontend can consume it, any speed up there will reduce latency getting data to the frontend and the other direction as well.

All of these things take CPU time, and if the backend is busy parsing JSON or serializing JSON it can’t also be making progress loading an integration at the same time as it has to wait (and yes, threads may switch off but that doesn’t make it take less time overall, actually more since you have the thread overhead).

1 Like

this is fundamental, and very well explained, thank you very much.
We need that in the docs somewhere…

so I moved to a Mini PC Celeron J4125, 8GB/128gB eMMC and yes this has improved. Underwhelmed though because it only cuts about 2% of my processor,

and still takes over 2 min for startup (was 4)

this is better too:

though as you can see still quite long.

option to do:

Not sure where MariaDB lives in my current hardware, but would suppose the 8Gb to be sufficient to run in there?

I will throw some new profile files at Nick, and hope he can see progress/advise!

Your results tend to point to the executor being overloaded. As there a limit to how many executor jobs can run at the same time regardless of how much hardware it thrown at the problem (adding more won’t help very much since it still has to switch thread contexts)

MQTT subscriptions generate an executor job per subscription core/client.py at b84e844c7679f48fe09fea68c228f2313eae2724 · home-assistant/core · GitHub so they will use hold one thread while each subscription is generated which is likely why it takes so long to startup. If they were grouped or done in a single executor job it could be a massive improvement. I don’t use MQTT so I’m not in a position to improve that as I can’t adequately test. I’ve already mentioned this to the Jan a few days ago, but I’m pretty sure they are busy with reloads.

Synology should be faster in the next release as it uses less executor jobs at startup.

Processing that is triggered from template is still exceptionally high in the profile (likely part of the CPU usage). It is not clear what the cause is, and a py-spy would likely be needed to track that down.

The other part is JSON overhead which should be solved by https://github.com/home-assistant/core/pull/72847 but that won’t change out the JSON decoder for unifi as the codeowner would have to add support for it after Home Assistant adds support once 72847 is merged.

talking about MQTT subscribes:
I now have the production system with the MQTT Integration subscribe to another HA instance running the MQTT Add-on.

Would it be beneficial to add the Add-on to the production system at all?

(I’ve split the 2 to spread the risk of breaking systems, and thinking it would relieve the main system from the server aspects of MQTT), but performance shouldn’t be hit, so if this would be worth the trouble of reconfiguring in your view, Id be glad to test that.)

It might help, but until the underlying issue is addressed I don’t think it will make much difference

ok, right, thanks.
so I wont move until then. lot of fuzz about nothing doesnt help anyone :wink:

It would be great if you can get py-spy working since we are only seeing data from the main thread.

If you install the ssh community addon and turn protection mode off you can access the container with

docker exec -it homeassistant /bin/bash

For the RPI4:

wget https://github.com/benfred/py-spy/releases/download/v0.3.12/py_spy-0.3.12-py2.py3-none-manylinux_2_17_armv7l.manylinux2014_armv7l.whl
unzip py_spy-0.3.12-py2.py3-none-manylinux_2_17_armv7l.manylinux2014_armv7l.whl

For the intel based one use https://github.com/benfred/py-spy/releases/download/v0.3.12/py_spy-0.3.12-py2.py3-none-manylinux_2_5_x86_64.manylinux1_x86_64.whl instead

There should be a py-spy binary once you call unzip in one of the directories it creates

I have the Terminal & SSH add-on installed, don’t see protection mode btw, and entering that command results in

If I plug the monitor in my Mini PC, I have the command prompt too, wouldn’t I be in the OS then? maybe I should enter the command there?

You need the community addon to disable protection mode. Make sure you have advanced turned on for the logged in user

1 Like

managed it up to here:

what do I do now?

I tried

pip install py-spy

according to GitHub - benfred/py-spy: Sampling profiler for Python programs but that fails because ‘cargo not found in PATH, please install RUST’

just to show what I have now:

progress, unzipped the file

and now have
Schermafbeelding 2022-06-19 om 13.27.05

or, in finder:

however, when I enter the --help command it is unknown…
Schermafbeelding 2022-06-19 om 13.29.25

or even:

Schermafbeelding 2022-06-19 om 13.31.53

so,I am almost there, but need some extra instructions please

how to find the correct --pid to record?
or should the py-spy file have an extension maybe? seems it simply isnt recognized as executable

Try running the one you extracted with ./py-spy

After you cd to the dir it was extracted to

hmmm, thats what I did.
Schermafbeelding 2022-06-19 om 15.43.32

btw, what does ./py-spy do? I never used that so maybe thats the source for issues…

also, these files now reside in the /config folder. Is that where they are supposed to be?

When you run a program without a path, $PATH is searched for the program. When you specify a path with ./ (aka current directory) your shell runs the program at that path

yes! that works!

right, so what do you need me to spy on exactly. if I enter ./py-spy top, it errors with no required --pid
so how do I find the correct pid for the instance you need

any of these (top in a normal terminal window) ?

ive just given that a shot using the 554 pid, and yet it returns:

even though I am doing what the link says to do:

You can also use py-spy from the Host OS to profile a running process running inside the docker container.

Or? am I in the wrong directory

Ive even tried to add –cap-add SYS_PTRACE to the ini_commands in the add-on options, but that results in a fatal issue…