Core: High CPU and memory usage under 0.108.0

[McGiverGim]

The problem

Since the installation of HA version 0.108.0 the CPU and memory usage in my system grows. I have restarted several times (HA and the raspberry) but this does not fix nothing.

This graph shows the difference from 0.107.7 to 0.108.0:

You can see the low CPU in blue and the memory stable at about 30% in red until the installation of 0.108.0. Since then the memory and the CPU grows in the time. I have restarted it several times without luck, as you see in the graph.

My first idea is to go back to 0.107.7 but I prefer to comment this here because maybe there is a bug and I can help giving information.

Environment

• Home Assistant Core release with the issue: 0.108.0
• Last working Home Assistant Core release (if known): 0.107.7
• Operating environment (Home Assistant/Supervised/Docker/venv): Hass.io
• Integration causing this issue: Unknown
• Link to integration documentation on our website: Unknown

Problem-relevant configuration.yaml

I don't know what to attach. My complete configuration?

Traceback/Error logs

I can't see any error, only the Brother that can't find the powered off printer, but this was the same in 0.107.7.

2020-04-09 08:39:56 ERROR (MainThread) [homeassistant.components.brother] Error fetching brother data: No SNMP response received before timeout
2020-04-09 08:39:56 WARNING (MainThread) [homeassistant.config_entries] Config entry for brother not ready yet. Retrying in 80 seconds.

Additional information

I have some custom integration, but they were there in earlier versions too:

• badnest
• nodered
• hacs

[andriej]

It's high probably that nodered is leaking.

[McGiverGim]

I'm doing tests disabling the custom integrations.
A docker stats command shows both, nodered and homeassistant growing in memory.
If I stop nodered, homeassistant stops to grow too. The CPU continues high with or without nodered.
So it seems nodered is the culprit (the most probable) or some sensor produced by nodered causes this in the system.
The strange thing is that this happens since the update to 0.108.0 it was not there in 0.107.7 or any previous version.

[gohm44]

I do not have any custom integration nodered and so on. After upgrade to the new version container consumes more resources. Eats more CPU usage and memory every minute... After ~12h I had to restart home assistant. I'm right after the upgrade to 0.108.1 but as far as I see it behave the same manner. My OS: Ubuntu 18.04

The new release introduced Jamalloc. Maybe it is our suspect?

Docker images for Home Assistant are now using Jemalloc, to reduce memory fragmentation and speed up memory allocation. So, less memory and generally a faster Home Assistant.

[McGiverGim]

Happy to hear that maybe is not node red related and I'm not alone in this problem. I think I see it with node red because I have sensors and flows that react from one to the other and maybe for some reason they don't do it like in the earlier version (maybe some sensor is out of control?).

I tested too 0.108.1 without luck, as you. I have made rollback to 0.107.7 and now all works as expected again.

If someone has some idea, I can upgrade again to 0.108.1 to test it, but until them, is impossible for me to remain in this version.

[Coren4]

I have already updated to 0.108.1 and I have te same issue.
CPU and memory usage is getting higher and higher, so around 24h after start both are above 90%.

Before 0.108 my CPU was around 5% on idle, and memory around 45%.

[gohm44]

A reboot of the server helped me to prevent constant increasing memory and CPU usage but anyway it's much higher than was before.

[AndrzejOlender]

I have the same problem, except for a high CPU and a large delay in HA at that time (the automatics worked with a few seconds delay) disk jump at the same time.


Intel NUC, HA Corde in docker 0.108.1

[Coren4]

0.108.2 it is still present

I use old 2 core/4gb RAM/SSD laptop as host with Ubuntu 18 Server.

What I use with HA:
ESPHome
Zigbee2Mqtt
Mqtt broker
Node red
Google drive backup
Plex integration
Airly integration
Brother printer integration
UPnP integration to network router

I am using MariaDB in container next to HA, as a storage.

[gohm44]

Actually I notice that for me 0.108.2 almost resolve the issue. Memory usage gets back to previous. CPU usage is still higher but at least constant.

[Coren4]

Actually I notice that for me 0.108.2 almost resolve the issue. Memory usage gets back to previous. CPU usage is still higher but at least constant.

I also thought it solved problem for me, but then 1h hour passed, and everything came back.

[McGiverGim]

The CPU usage as high is a clear symptom that the problem is still there.
While I was playing starting and stopping nodered to see if it goes better, I thought I fixed it because at some moment the memory was stable, but the CPU was high and some time later the memory started to grow again.

[mountainsandcode]

Struggling with the same issue

[McGiverGim]

@mountainsandcode can you give more information about your system? Are you using unofficial integrations like Node Red?

[mountainsandcode]

I'm running HASS on a Synology using Docker - I have HACS running and two self-programmed integrations, but they have been running for quite a while. I suspect this may be due to https://github.com/home-assistant/core/issues/33882#issuecomment-612424222 as I can also see two python processes

[Coren4]

I don't have Homekit integration, so in my case I don't think it is it.

[haseat]

Having the same problem in Home Assistant Core on a Pi4 since upgrading to 0.108.n, although on a much lower level. As you can see, memory usage goes up until a restart.

[Alessandro1981]

I have the same issue updating from 107.7 to 108.3. Rolling back to version 107.7 the issue disappeared (memory consumption is flat).

Alessandro

[SquareBeard]

Same issue. I'm using docker on a i5 and I'm not using Nodered.
Problem appeared with v108.0.
I have to restart the container often because all services starts to timeout.

[AndrzejOlender]

I also have a HA Core in Docker, maybe the last change is the cause of the problem?

Docker images for Home Assistant are now using Jemalloc, to reduce memory fragmentation and speed up memory allocation. So, less memory and generally a faster Home Assistant.

[gohm44]

Since version 0.108.3 everything goes back to normal for me.

[McGiverGim]

It does not fix the problem for me. Tested it today with 0.108.3 and you can see again the memory going up and the CPU going up and down :

EDIT:
I edit to give more information. The memory is wasted in the homeassistant docker. After the installation:

Some time later:

The rest of addons seems to be stable.

A ps inside the homeassistant docker does not reveal nothing strange.

[choeflake]

Same here (except the memory). Issue experienced first with 0.108.? then upgraded to 0.108.3, still the same. Now back to 0.107.7 and issue is gone (all other components are not downgraded).
Under 0.108.x, my log was full of events like:

ha             | 2020-04-13 22:22:17 INFO (MainThread) [homeassistant.components.mqtt] Got update for entity with hash: ('binary_sensor', '0x0017880104b53dcc occupancy') '{'payload_on': True, 'payload_off': False, 'value_template': '{{ value_json.occupancy }}', 'device_class': 'motion', 'state_topic': 'zigbee2mqtt/hal_1_sensor_1', 'json_attributes_topic': 'zigbee2mqtt/hal_1_sensor_1', 'name': 'hal_1_sensor_1_occupancy', 'unique_id': '0x0017880104b53dcc_occupancy_zigbee2mqtt', 'device': {'identifiers': ['zigbee2mqtt_0x0017880104b53dcc'], 'name': 'hal_1_sensor_1', 'sw_version': 'Zigbee2mqtt 1.12.2', 'model': 'Hue motion sensor (9290012607)', 'manufacturer': 'Philips'}, 'availability_topic': 'zigbee2mqtt/bridge/state', 'platform': 'mqtt'}'
ha             | 2020-04-13 22:22:17 INFO (MainThread) [homeassistant.components.mqtt] Updating component: binary_sensor.hal_1_sensor_1_occupancy

(not sure which of the two rows is first)

For every entity (thus devices multiplied by the number of entities on it), this log is written every second.

My config: Ubuntu with Docker Compose running mosquitto 1.6.9, Zigbee2mqtt 1.12.2 (firmware 20200328). Stopping the mosquitto container reduces the CPU, listening on the MQTT shows that hundreds of messages per second are processed.

[haseat]

0.108.4 seems to have fixed the problem for me so far

[andriej]

@haseat according to changelog nothing seems to be changed regarding system.
Maybe you've updated HACS meanhwile too?

[haseat]

@andriej you're right, I totally forgot about that, but I did it right before the 0.108.4 update

[McGiverGim]

My latest test with 0.108.3 was with HACS updated to the latest version, and that did not fix the problem for me :(

[McGiverGim]

I have observed that some users use py-spy to analyze what is going on with the system, one example on this thread:

https://github.com/home-assistant/core/issues/34093

Someone from here is able to execute it? I don't know nothing about python so I don't know if it can be executed in a running released hass.io/homeassistant instance.

[McGiverGim]

Other user with problems in reddit too: https://www.reddit.com/r/homeassistant/comments/fykg8l/ha_108_on_roller_coaster_cpumem_ride/

[Lawrencezarb]

I have the same problem, even using 108.4. I have reverted to 107.7

[Gunth]

I also have the same issue with the 108.5 version .... :-(

[McGiverGim]

Nobody here is able to install and execute py-spy? https://github.com/benfred/py-spy

I have tried, but it seems the instructions are not valid for Hass.io or my system.

[D43m0n666]

Same problem for me with 108.4. Rollback to 108.2 solved the problem.
I've installed HA in Raspberry 3B+ with 1GB RAM and assigned 1GB for SWAP.
No HACS and no custom integration

[ayufan]

It seems that the fix for me was to disable Brother integration. My brother is mostly not running, but it seems that HA and Brother do enqueue a number of requests for fetching data even though device does not respond.

Maybe this is problem with the Brother integration, but this could as well be problem in a state update loop that it re-enqueues fetching of data even though the previous op did not finish.

2020-04-16 09:21:12 ERROR (MainThread) [homeassistant.components.brother] Unexpected error fetching brother data:
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/dist-packages/homeassistant/helpers/update_coordinator.py", line 129, in async_refresh
    self.data = await self._async_update_data()
  File "/usr/local/lib/python3.7/dist-packages/homeassistant/components/brother/__init__.py", line 80, in _async_update_data
    await self.brother.async_update()
  File "/srv/homeassistant/deps/lib/python3.7/site-packages/brother/__init__.py", line 43, in async_update
    raw_data = await self._get_data()
  File "/srv/homeassistant/deps/lib/python3.7/site-packages/brother/__init__.py", line 145, in _get_data
    *request_args, *self._oids
  File "/usr/lib/python3.7/asyncio/coroutines.py", line 123, in coro
    res = yield from res
concurrent.futures._base.CancelledError
2020-04-16 09:21:12 ERROR (MainThread) [homeassistant.components.brother] Unexpected error fetching brother data:
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/dist-packages/homeassistant/helpers/update_coordinator.py", line 129, in async_refresh
    self.data = await self._async_update_data()
  File "/usr/local/lib/python3.7/dist-packages/homeassistant/components/brother/__init__.py", line 80, in _async_update_data
    await self.brother.async_update()
  File "/srv/homeassistant/deps/lib/python3.7/site-packages/brother/__init__.py", line 43, in async_update
    raw_data = await self._get_data()
  File "/srv/homeassistant/deps/lib/python3.7/site-packages/brother/__init__.py", line 145, in _get_data
    *request_args, *self._oids
  File "/usr/lib/python3.7/asyncio/coroutines.py", line 123, in coro
    res = yield from res
concurrent.futures._base.CancelledError
2020-04-16 09:21:12 ERROR (MainThread) [homeassistant.components.brother] Unexpected error fetching brother data:
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/dist-packages/homeassistant/helpers/update_coordinator.py", line 129, in async_refresh
    self.data = await self._async_update_data()
  File "/usr/local/lib/python3.7/dist-packages/homeassistant/components/brother/__init__.py", line 80, in _async_update_data
    await self.brother.async_update()
  File "/srv/homeassistant/deps/lib/python3.7/site-packages/brother/__init__.py", line 43, in async_update
    raw_data = await self._get_data()
  File "/srv/homeassistant/deps/lib/python3.7/site-packages/brother/__init__.py", line 145, in _get_data
    *request_args, *self._oids
  File "/usr/lib/python3.7/asyncio/coroutines.py", line 123, in coro
    res = yield from res
concurrent.futures._base.CancelledError

# and like x20 more

It seems that major aspects at least changed for Brother: https://github.com/home-assistant/core/commit/c1ceab09e5281dcf6b42592bb2e35cb6518f4885#diff-cb38b021b379128e76bd5b1f539660ca.

[D43m0n666]

I've also Brother integration. I try to disable it and upgrade HA...I let you know!

[SquareBeard]

I have no Brother integration and it is still not working with v108.5

[ayufan]

So far, is good (after removing Brother):

As, stated, it could be some generic component that is responsible for updating entities, that it repeats device update aggressively when it is unavailable. I just see this happening on Brother, as this is unavail for me for most of time.

[McGiverGim]

I have the Brother integration, but I think remember I installed it after the problem, but I will try later without it.

@D43m0n666 waiting for your test...

@SquareBeard do you have any message in the "developer tools", "registry" that repeats a lot? Maybe is not the Brother integration, but any integration that does not detect the device and tries to find it.

[SquareBeard]

@McGiverGim That is indeed a good possibility, I have a device that is always off. I'll try to desactivate it.

[D43m0n666]

I have the Brother integration, but I think remember I installed it after the problem, but I will try later without it.

@D43m0n666 waiting for your test...

Disabling Brother integration it seems ok with latest release 108.5, FOR NOW! I can give you better news in 24H, thanks @ayufan for suggestion!

[SquareBeard]

Well that worked. My HA instance has not been running that long since v107.

There is definitely something wrong with unreachable devices or with the logging of the errors related to such devices.

[Gunth]

I also have a Brother printer, i need to check this ...

[McGiverGim]

Disabled the Brother integration and all seems stable too... maybe we have found the problem. I will check in the next hours but it looks good until now.

I don't know if some developer is following this thread or is there a way to make them aware of that...

[ayufan]

@bieniu Can you take a look as you are the author of latest changes? https://github.com/home-assistant/core/commit/c1ceab09e5281dcf6b42592bb2e35cb6518f4885#diff-cb38b021b379128e76bd5b1f539660ca

[SquareBeard]

@ayufan It is not related to the Brother integration.
It's seems to be related to unreachable devices and/or logging.

[bieniu]

@ayufan I'm looking for issue in code since your first post about brother but I don't see anything suspicious. On my 3 devices, the CPU load is the same with and without brother integration and with the priter turned on or turned off.

[ayufan]

@SquareBeard It seems so, but someone familiar with lifecycle of devices could help out with testing it and git bisecting :)

[SquareBeard]

@bieniu Did you try with your printers powered off ?

[bieniu]

@SquareBeard Yes.

[ayufan]

@bieniu This starts to happen after long period. For example I noticed a bunch of messages failing to get SNMP data due to timeout/missing DNS/UDP connection. Also, SNMP seems to have failed as well when printer was powered on.

[bieniu]

@ayufan OK I will turn off my printer for the whole day.

[McGiverGim]

I have bad news... Mine seems has started to eat memory, without the Brother integration 😭

[McGiverGim]

I have bad news... Mine seems has started to eat memory, without the Brother integration 😭

Maybe is a different problem now... the memory grow but the CPU remained stable, and seeing the processes inside the homeassistant container I can see two homeassistant processes:

I have restarted the server again, the second process has disappeared and now all seems stable again... I will inform later.

[McGiverGim]

Three hours later I can confirm is smooth and stable, so is clear that the problem is the Brother integration or is more general and has something to do with sensors powered off.

[ayufan]

I re-enabled Brother. I see increasing CPU-usage. This seems overall fine, the message:

Apr 16 15:55:22 hass hass[593]: 2020-04-16 15:55:22 ERROR (MainThread) [homeassistant.components.brother] Error fetching brother data: No SNMP response received before timeout
Apr 16 15:55:22 hass hass[593]: 2020-04-16 15:55:22 WARNING (MainThread) [homeassistant.config_entries] Config entry for brother not ready yet. Retrying in 80 seconds.
Apr 16 15:57:10 hass hass[593]: 2020-04-16 15:57:10 ERROR (MainThread) [homeassistant.components.brother] Error fetching brother data: No SNMP response received before timeout
Apr 16 15:57:10 hass hass[593]: 2020-04-16 15:57:10 WARNING (MainThread) [homeassistant.config_entries] Config entry for brother not ready yet. Retrying in 80 seconds.
Apr 16 15:58:59 hass hass[593]: 2020-04-16 15:58:59 ERROR (MainThread) [homeassistant.components.brother] Error fetching brother data: No SNMP response received before timeout
Apr 16 15:58:59 hass hass[593]: 2020-04-16 15:58:59 WARNING (MainThread) [homeassistant.config_entries] Config entry for brother not ready yet. Retrying in 80 seconds.

OK. I enabled debug logs on brother integration:

Apr 16 16:00:48 hass hass[593]: 2020-04-16 16:00:48 ERROR (MainThread) [homeassistant.components.brother] Error fetching brother data: No SNMP response received before timeout
Apr 16 16:00:48 hass hass[593]: 2020-04-16 16:00:48 DEBUG (MainThread) [homeassistant.components.brother] Finished fetching brother data in 28.083 seconds
Apr 16 16:00:48 hass hass[593]: 2020-04-16 16:00:48 WARNING (MainThread) [homeassistant.config_entries] Config entry for brother not ready yet. Retrying in 80 seconds.
Apr 16 16:00:51 hass hass[593]: 2020-04-16 16:00:51 DEBUG (MainThread) [homeassistant.components.brother] Finished fetching brother data in 27.596 seconds
Apr 16 16:00:52 hass hass[593]: 2020-04-16 16:00:52 DEBUG (MainThread) [homeassistant.components.brother] Finished fetching brother data in 27.597 seconds
Apr 16 16:00:53 hass hass[593]: 2020-04-16 16:00:53 DEBUG (MainThread) [homeassistant.components.brother] Finished fetching brother data in 27.593 seconds
Apr 16 16:00:53 hass hass[593]: 2020-04-16 16:00:53 DEBUG (MainThread) [homeassistant.components.brother] Finished fetching brother data in 27.411 seconds
Apr 16 16:00:58 hass hass[593]: 2020-04-16 16:00:58 DEBUG (MainThread) [homeassistant.components.brother] Finished fetching brother data in 27.752 seconds
Apr 16 16:00:59 hass hass[593]: 2020-04-16 16:00:59 DEBUG (MainThread) [homeassistant.components.brother] Finished fetching brother data in 27.459 seconds
Apr 16 16:00:59 hass hass[593]: 2020-04-16 16:00:59 DEBUG (MainThread) [homeassistant.components.brother] Finished fetching brother data in 27.287 seconds
Apr 16 16:00:59 hass hass[593]: 2020-04-16 16:00:59 DEBUG (MainThread) [homeassistant.components.brother] Finished fetching brother data in 27.107 seconds
Apr 16 16:00:59 hass hass[593]: 2020-04-16 16:00:59 DEBUG (MainThread) [homeassistant.components.brother] Finished fetching brother data in 26.936 seconds
Apr 16 16:00:59 hass hass[593]: 2020-04-16 16:00:59 DEBUG (MainThread) [homeassistant.components.brother] Finished fetching brother data in 26.749 seconds
Apr 16 16:00:59 hass hass[593]: 2020-04-16 16:00:59 DEBUG (MainThread) [homeassistant.components.brother] Finished fetching brother data in 26.577 seconds
Apr 16 16:00:59 hass hass[593]: 2020-04-16 16:00:59 DEBUG (MainThread) [homeassistant.components.brother] Finished fetching brother data in 26.428 seconds
Apr 16 16:00:59 hass hass[593]: 2020-04-16 16:00:59 DEBUG (MainThread) [homeassistant.components.brother] Finished fetching brother data in 26.259 seconds
Apr 16 16:00:59 hass hass[593]: 2020-04-16 16:00:59 DEBUG (MainThread) [homeassistant.components.brother] Finished fetching brother data in 26.084 seconds
Apr 16 16:00:59 hass hass[593]: 2020-04-16 16:00:59 DEBUG (MainThread) [homeassistant.components.brother] Finished fetching brother data in 25.909 seconds
Apr 16 16:00:59 hass hass[593]: 2020-04-16 16:00:59 DEBUG (MainThread) [homeassistant.components.brother] Finished fetching brother data in 25.813 seconds
Apr 16 16:00:59 hass hass[593]: 2020-04-16 16:00:59 DEBUG (MainThread) [homeassistant.components.brother] Finished fetching brother data in 25.647 seconds
Apr 16 16:00:59 hass hass[593]: 2020-04-16 16:00:59 DEBUG (MainThread) [homeassistant.components.brother] Finished fetching brother data in 25.400 seconds
Apr 16 16:00:59 hass hass[593]: 2020-04-16 16:00:59 DEBUG (MainThread) [homeassistant.components.brother] Finished fetching brother data in 25.208 seconds
Apr 16 16:00:59 hass hass[593]: 2020-04-16 16:00:59 DEBUG (MainThread) [homeassistant.components.brother] Finished fetching brother data in 25.031 seconds
Apr 16 16:00:59 hass hass[593]: 2020-04-16 16:00:59 DEBUG (MainThread) [homeassistant.components.brother] Finished fetching brother data in 24.863 seconds
Apr 16 16:00:59 hass hass[593]: 2020-04-16 16:00:59 DEBUG (MainThread) [homeassistant.components.brother] Finished fetching brother data in 24.691 seconds
Apr 16 16:00:59 hass hass[593]: 2020-04-16 16:00:59 DEBUG (MainThread) [homeassistant.components.brother] Finished fetching brother data in 24.521 seconds
Apr 16 16:00:59 hass hass[593]: 2020-04-16 16:00:59 DEBUG (MainThread) [homeassistant.components.brother] Finished fetching brother data in 24.351 seconds
Apr 16 16:00:59 hass hass[593]: 2020-04-16 16:00:59 DEBUG (MainThread) [homeassistant.components.brother] Finished fetching brother data in 24.183 seconds
Apr 16 16:00:59 hass hass[593]: 2020-04-16 16:00:59 DEBUG (MainThread) [homeassistant.components.brother] Finished fetching brother data in 24.013 seconds
Apr 16 16:00:59 hass hass[593]: 2020-04-16 16:00:59 DEBUG (MainThread) [homeassistant.components.brother] Finished fetching brother data in 23.843 seconds
Apr 16 16:00:59 hass hass[593]: 2020-04-16 16:00:59 DEBUG (MainThread) [homeassistant.components.brother] Finished fetching brother data in 23.679 seconds

This does not seem right, it seems that there's a number of enqueued watchers, but it could be as well a number of sensors watching on a data.

However, this also leads me to the conclusion that brother sensors might enqueue a number of new queries against a coordinator, as usually they would be fast to respond, but it is not true. Now, this creates a case where, we have 20 listeners (each sensor, 20 is a some random number number, as I don't know how many are there). Now, each of the sensors wants to update its state, so it enqueues await. Now, this times out, resulting each sensor (as each sensor did enqueue async op) to update all listeners.

@bieniu I wonder about above :)

[bieniu]

After 4 hours from turning off the printer:

[ayufan]

@bieniu I wonder, I noticed that it might have a difference in behaviour between if during startup brother is up or not. I was mostly testing that brother was down while starting HASS, so it was shutdown before the HASS restart. Maybe, if you shutdown it while it was HASS is running, some data might be still cached.

[bieniu]

@ayufan Brother sensors don't pool for data. They have should_pool property set to False: https://github.com/home-assistant/core/blob/dev/homeassistant/components/brother/sensor.py#L128-L131

Integration uses DataUpdateCoordinator class and those log entries are from this class.

brother library uses timeout 2 sec and retries 10 times so fetching data about 20 seconds when device is offline is normal.

[McGiverGim]

In not too sure what this message implies, but they seem too much for the same second.
I can confirm my system continues stable after several hours without brother integration.

[ayufan]

@bieniu

As far as I can see, they do request data from coordinator which might enqueue multiple data requests. Now, since coordinator registers listeners it is likely that each sensor might request a new await. I have no idea if this is problem with Brother or the DataUpdateCoordinator, but symptoms are as here: https://github.com/home-assistant/core/issues/33866#issuecomment-614741425. It seems also off that we seem to consume a multiple results at the same time, this does mean that multiple awaits are enqueued and finish at the same time.

Now, after re-testing again with Brother power off, HASS restarted I clearly see an increasing in CPU usage, something that is not happening when Brother integration is disabled:
.

Can you re-test on your side with the following conditions? For reference I run HASS on armv7l, so it might take significantly longer to see increasing CPU usage on much more beefy processors (like amd64).

[bieniu]

OK guys, I have to admit that something is wrong.
I added _LOGGER.debug(f"update: {self}") to _async_update_data method of BrotherDataUpdateCoordinator class. When I start HA when the printer is offline after some time I have in log:

2020-04-16 22:49:43 DEBUG (MainThread) [homeassistant.components.brother] update: <homeassistant.components.brother.BrotherDataUpdateCoordinator object at 0x7f332346adc0>
2020-04-16 22:50:04 DEBUG (MainThread) [homeassistant.components.brother] update: <homeassistant.components.brother.BrotherDataUpdateCoordinator object at 0x7f32e6e6bc70>
2020-04-16 22:50:04 DEBUG (MainThread) [homeassistant.components.brother] update: <homeassistant.components.brother.BrotherDataUpdateCoordinator object at 0x7f335794db50>
2020-04-16 22:50:56 DEBUG (MainThread) [homeassistant.components.brother] update: <homeassistant.components.brother.BrotherDataUpdateCoordinator object at 0x7f32e6ab8160>

Four different coordinator objects are trying to update the data from the printer.
I think that every attempt to configure brother integrations adds new coordinator object. Each coordinator object is trying to update the data from the printer and it takes memory and CPU time.

EDIT:
This piece of code is to blame for that: https://github.com/home-assistant/core/blob/dev/homeassistant/components/brother/__init__.py#L33-L37
Each integration that uses DataUpdateCoordinator works the same way.

[McGiverGim]

Good catch @bieniu ! Let's go for the fix! 😁

[bieniu]

Fix: https://github.com/home-assistant/core/pull/34317

[choeflake]

Ok, but I have high CPU and no brother integration. So I think the problem is more general. My log is full of messages about updating components (see above).
My setup uses MQTT and Zibee2MQTT plus Node Red.

[SquareBeard]

The fix applies to all integration using DataUpdateCoordinator. Hopefully it will fix our problem too.

[ayufan]

I updated my install. Will monitor :) Thanks @bieniu :)

So far graphs are significantly more healthy.

[D43m0n666]

I have the Brother integration, but I think remember I installed it after the problem, but I will try later without it.
@D43m0n666 waiting for your test...

Disabling Brother integration it seems ok with latest release 108.5, FOR NOW! I can give you better news in 24H, thanks @ayufan for suggestion!

Yes, i confirm problem was Brother integration. Now it's ok, i've also updated to latest version!

Thanks to all!

[bieniu]

@D43m0n666 This was a Data Update Coordinator issue and affected all integrations using it.

[ayufan]

So far, everything seems stable.

On Fri, Apr 17, 2020 at 2:47 PM Maciej Bieniek [e-mail]
wrote:

@D43m0n666 https://github.com/D43m0n666 This was a Data Update
Coordinator issue and affected all integrations using it.

—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
https://github.com/home-assistant/core/issues/33866#issuecomment-615224695,
or unsubscribe
https://github.com/notifications/unsubscribe-auth/AASOSQJVFNCGHPB7I26WNKDRNBFUXANCNFSM4MEP6JRQ
.

[ayufan]

It is definitely a magnitude better, but for me it still seems that there's some performance impact of having and not having Brother enabled:

As you can see baseline did jump from ~4.5% to ~6% of CPU usage (given that this is not the only task running there it is in fact 33% increase in CPU usage) after upgrade from 0.108.4 to 0.108.8. The only other difference is I enabled Brother integration.

I'm running another test now. I disabled and lets see the difference in next 12/18 hours :)

[andriej]

1,5% percent of difference between having and not having snmp queries in background... what hardware are you on where it matters? ;-)

[choeflake]

Upgraded tot 0.108.6, seems to fix a lot. My CPU is now around 5%. In my opinion this is not 'low', but way better than the previous 60%.
Take note that I have a 'Intel(R) Core(TM) i7-3632QM CPU @ 2.20GHz' cpu. The 5 min load shows 0.05.

[ayufan]

@andriej @bieniu

Given that this machine is: my router, dual wifi with 5 SSIDs, firewall, VPN server, HASS (with 100 entities), zigbee2mqtt (with 40 entities), Prometheus scraping 15 targets, MQTT, esphome frontend, and pihole it is doing pretty well with that average.

There is a clearly noticeable performance regression when running brother integration with a printer being unreachable. It is very likely that it was as that before, but it still does not make sense to use so much resources by service where there's in fact no data processing.

I will look how performant is brother module :)

EDIT:

It takes around 140ms for me to perform a single cycle of brother.async_update for unavailable device. This time is spend solely on CPU.

EDIT 2:

The problem is related for the cost of running snmp_engine = hlapi.SnmpEngine(). This requires parsing all OIDs database it seems. This takes takes that CPU time. I see around 130ms being spend on just this call.

EDIT 3:

This happens as the whole OID database seems to be imported each time: https://github.com/etingof/pysnmp/blob/master/pysnmp/entity/engine.py#L99.

Likely, it would be better to re-use hlapi.SnmpEngine() across different printers, and initialize it once, instead of each time when requesting data. This is also probably why we saw so siginificant performance regression, as more and more of hlapi.SnmpEngine() ops were queued, and each of them took significant amount of time.

It seems that a single snmp_engine object takes around 40kB in memory, so likely this is fully acceptable given the very high cost of initialization. Considering, that having 130ms initialization time each time to fetch data creates a random latency spikes in responsiveness of Home Assistant, due to GIL of CPython :)

EDIT 4:

Initing snmp_engine once results in the check being instantaneous.

[Alessandro1981]

Updating to 108.6 fix the issue on my installation: memory and CPU are as expected

[McGiverGim]

All is ok for me. It seems that my cpu is maybe a little bigger (maybe 1%) but I don't know if this can be addressed or where the origin is.

[McGiverGim]

After two days os testing, all seems stable but I see my memory a little high. The home assistant docker is taking more than 400M. It has been taken more memory slowly. The memory total is about 50% (Raspberry Pi 2Gb).

Usually I had less memory used, but I'm always changing things, so maybe is simply normal but I comment about this here to see if more people has noticed something. As I say it seems stable and I have no problems.

[Gunth]

Yes, it seems that i have the same issue, memory and swap is growing to 100% for both after 2 days on my RPi3b+

[eddetollenaer]

I have the same problem. I see a clear increase of memory usage every hour during the night when not much is going on rather than one automation that determines the max day temperature every 15 minutes. I already set the recorder to only record the automations and two sensors because the recorder send to eat up a lot of memory.

[bullshitduckdnsaccount]

I had this same issue as well, starting in 0.108.0 and the changes in 0.108.6 did fix it for me.

The issue then returned in 0.109.0 and has consisted through 0.110.x. Both CPU and RAM will creep up and then eventually bring HA to a standstill until rebooted.

[norbertomartins]

I have the version 0.110.3 and have the same issue. I created a trigger to reboot if memory is below 110 for more than 2 minutes. Sometimes this occurs during the night.

[andriej]

Ain't it google backup addon doing it's job?

[bdraco]

Please post a py-spy recording
https://github.com/benfred/py-spy

py-spy record --pid 200 --output issue33866.svg --duration 120

You'll have to change the pid to your local instance's pid.

[stale[bot]]

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 now has been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.