statistics on 2024.5.0 causing increased CPU usage and high temps #116650

myromeo · 2024-05-02T19:42:43Z

The problem

Updated to 2024.5.0 and noted an increase in CPU usage (around 5% higher) resulting in CPU temps increasing by 30%+. Rolled back to 2024.4.4 and usage and temps immediately dropped.

What version of Home Assistant Core has the issue?

core-2024.5.0

What was the last working version of Home Assistant Core?

core-2024.4.4

What type of installation are you running?

Home Assistant OS

Integration causing the issue

No response

Link to integration documentation on our website

No response

Diagnostics information

No response

Example YAML snippet

No response

Anything in the logs that might be useful for us?

Can’t see any errors and everything is running.

Additional information

X64, intel i5-4590T on Lenovo m93p tiny.

bdraco · 2024-05-02T22:56:31Z

Please post a callgrind file from the profiler

https://my.home-assistant.io/redirect/config_flow_start/?domain=profiler
https://my.home-assistant.io/redirect/developer_call_service/?service=profiler.start

nijel · 2024-05-03T07:20:40Z

I observe the same symptoms, callgrind is here:

callgrind.out.1714720380542446.txt

If I read it correctly, it seems to be caused by statistics platform sensors in my case.

home-assistant · 2024-05-03T07:25:44Z

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

Code owner commands

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

statistics documentation
statistics source
_{^{(message by IssueLinks)}}

bdraco · 2024-05-03T07:27:03Z

If I read it correctly, it seems to be caused by statistics platform sensors in my case.

Spot on
72 million calls to total_seconds

bdraco · 2024-05-03T07:28:12Z

#110438 will probably fix it, but I never did get time to get back to iterate on that PR

nijel · 2024-05-03T07:32:02Z

Any clue why this appeared with the 2024.5? The statistics code doesn't seem to be changed recently.

bdraco · 2024-05-03T07:36:29Z

Its been a problem for a while, and seems to come up every time the timings change a bit, see #110433

I'm not exactly sure what triggers the issue as I've never been able to fully replicate it to the degree you have in your profile.

bdraco · 2024-05-03T07:43:03Z

_initialize_from_database could be refactored to only look at the last state to set the attributes instead of doing the calculations inside of _add_state_to_queue for every previous state and throwing it away.

That would probably help as well

nijel · 2024-05-03T07:46:04Z

In my case, it seems to be caused by 30 minute average_linear statistics for a frequently updated sensor. I should probably look for a better way to achieve the same.

PS: After changing a bit calculation formula for the originating sensor, I'm down to 12M calls of total_seconds and my system no longer runs fans on full power. Still, this is the most CPU intensive operation my Home Assistant does.

ayavilevich · 2024-05-03T14:50:45Z

I am having an issue with statistics since upgrade to 2024.5.0 too.

Here is the CPU graph:

It starts normal after a restart but then after a few hours gradually becomes CPU over loaded.

I ran the profiler. High CPU places are:

statistics.py:154(_sum)
~:0(<method 'as_integer_ratio' of 'float' objects>)
statistics.py:287(_exact_ratio)

I use statistics a lot but didn't have an issue before.
Going to rollback now.

bdraco · 2024-05-03T15:05:39Z

I think the performance problems could be solved, by breaking out the code into a new object, and then breaking that out into a package, it could also be Cythonized to do all the calculations in native code.

Another alternative would be to rewrite the expensive operations in numpy

myromeo · 2024-05-03T15:57:36Z

callgrind.out.1714751198628950.txt

As requested callgrind file. How do I make sense of this file as I have no idea what I am looking at!

ayavilevich · 2024-05-03T16:07:16Z

callgrind.out.1714751198628950.txt

As requested callgrind file. How do I make sense of this file as I have no idea what I am looking at!

See https://www.home-assistant.io/integrations/profiler

For example, you can use SnakeViz to render it and see what functions consume most of the CPU.

Correction, SnakeViz is for the .cprof. There are other software for the callgrind.

ThomDietrich · 2024-05-03T20:25:56Z

Hey guys, hey @bdraco,
this sounds horrible. Any idea what caused that issue? My first guess would be that this might be related to the introduction of state_reported events, however the statistics component doesn't use that one yet. I'm thinking there might have been another change that lead to this.

bdraco · 2024-05-03T20:43:22Z

@ayavilevich

callgrind.out.1714751198628950.txt

As requested callgrind file. How do I make sense of this file as I have no idea what I am looking at!

Looks like this case of many sqlite queries.

Can you turn on info (maybe even debug) logging for sqlalchemy as well?

myromeo · 2024-05-03T20:45:15Z

how do I do that?

bdraco · 2024-05-03T20:45:58Z

service: logger.set_level
data:
  sqlalchemy: info

bdraco · 2024-05-03T20:47:09Z

Hey guys, hey @bdraco, this sounds horrible. Any idea what caused that issue? My first guess would be that this might be related to the introduction of state_reported events, however the statistics component doesn't use that one yet. I'm thinking there might have been another change that lead to this.

I'm not really sure whats going on at this point as it seems all the profiles have a lot of database access going on, but AFAICT _initialize_from_database is only ever called once per entity.

bdraco · 2024-05-03T20:51:11Z

The only thing I can think is the database access is unrelated and because of the busy system otherwise as _initialize_from_database doesn't appear in the profile

bdraco · 2024-05-03T20:52:20Z

Maybe there is some type of race in _next_to_purge_timestamp and its scheduling the next update too soon so its updating over and over again

core/homeassistant/components/statistics/sensor.py

Line 548 in 81a269f

self.hass, _scheduled_update, timestamp

bdraco · 2024-05-03T21:01:16Z

service: logger.set_level
data:
  sqlalchemy: info
  homeassistant.components.statistics: debug

It would be good to get debug logs for statistics as well so we can tell if its the scheduling update firing too often

myromeo · 2024-05-03T21:03:32Z

@bdraco I've set that, what next?

ayavilevich · 2024-05-03T21:33:10Z

I am not sure if that is relevant, but since you mentioned database activity, I would like to add that I am using MariaDB as the database for the recorder.
Is that common to others who are having the issue?

bdraco · 2024-05-03T22:07:31Z

@bdraco I've set that, what next?

Please post the log (remove anything sensitive)

dannytsang · 2024-05-03T23:03:18Z

home-assistant.log

bdraco · 2024-05-03T23:46:17Z

Maybe I'm reading this wrong and the time zones aren't aligned, but it looks like it trying to schedule updates in the past which than execute right away

2024-05-03 23:37:20.850 DEBUG (MainThread) [homeassistant.components.statistics.sensor] sensor.home_electricity_power_standard_deviation_over_an_hour: scheduling update at 2024-05-03 23:36:44.809911+00:00

bdraco · 2024-05-03T23:54:50Z

It looks like its scheduling an update to make sure old states are purged but it doesn't actually purge the state so the next update gets scheduled in the past because its expected it had purged the state, and than it tries to do it again and again

bdraco · 2024-05-04T00:02:04Z

I've not had any luck replicating the problem.

Can you post your config for statistics?

bdraco · 2024-05-04T00:16:35Z

#116743 should eliminate the chance of a race unless there is a bug in the time calculation.

Can be tested with

cd /config
curl -o- -sSL https://gist.githubusercontent.com/bdraco/43f8043cb04b9838383fd71353e99b18/raw/core_integration_pr | bash /dev/stdin -d statistics -p 116743

to4ko · 2024-05-04T06:50:45Z

#116743 should eliminate the chance of a race unless there is a bug in the time calculation.

Can be tested with
cd /config
curl -o- -sSL https://gist.githubusercontent.com/bdraco/43f8043cb04b9838383fd71353e99b18/raw/core_integration_pr | bash /dev/stdin -d statistics -p 116743

applied the fix above...its kinda better, but still way not even close to pre-2024.5.x versions

fix applied this morning (red line)

this is how i was before May - massive cpu heating started this Wednesday May 1.

dannytsang · 2024-05-04T11:20:47Z

I've not had any luck replicating the problem.

Can you post your config for statistics?

Here are all mine. I use packages so they are not all in a single file (if that makes any difference):

sensor:
  - platform: statistics
    name: "Home Electricity Power Average Over An Hour"
    unique_id: 97f8c377-acd2-4d92-a2f2-6bbf5ca0b110
    entity_id: sensor.growatt_sph_load_power
    state_characteristic: mean
    max_age:
      hours: 1
  - platform: statistics
    name: "Home Electricity Power Average Over A Day"
    unique_id: 74b261eb-6feb-473d-87b4-8eca961be99d
    entity_id: sensor.growatt_sph_load_power
    state_characteristic: mean
    max_age:
      hours: 24
  - platform: statistics
    name: "Home Electricity Power Average Over A Week"
    unique_id: 47f78be2-bea5-499c-926b-50b48f92f202
    entity_id: sensor.growatt_sph_load_power
    state_characteristic: mean
    max_age:
      days: 7
  - platform: statistics
    name: "Home Electricity Power Average Over A Month"
    unique_id: c0b7e702-5468-4cb1-8221-8067cf44c3e1
    entity_id: sensor.growatt_sph_load_power
    state_characteristic: mean
    max_age:
      days: 30
  - platform: statistics
    name: "Home Electricity Power Median Over An Hour"
    unique_id: b9256d7e-504c-43e2-ac7d-f77ed5b69aaa
    entity_id: sensor.growatt_sph_load_power
    state_characteristic: median
    max_age:
      hours: 1
  - platform: statistics
    name: "Home Electricity Power Median Over A Day"
    unique_id: 82ff2fd7-2694-4171-b0ec-3cafc52205cf
    entity_id: sensor.growatt_sph_load_power
    state_characteristic: median
    max_age:
      hours: 24
  - platform: statistics
    name: "Home Electricity Power Median Over A Week"
    unique_id: fe221135-0a10-414b-8954-137ea83aa73f
    entity_id: sensor.growatt_sph_load_power
    state_characteristic: median
    max_age:
      days: 7
  - platform: statistics
    name: "Home Electricity Power Median Over A Month"
    unique_id: 5891e92f-7bbc-4c51-941e-aa005fba93f9
    entity_id: sensor.growatt_sph_load_power
    state_characteristic: median
    max_age:
      days: 30
  - platform: statistics
    name: "Home Electricity Power Standard Deviation Over An Hour"
    unique_id: 3b115d2e-f765-4e47-b53d-03ff61ca6ada
    entity_id: sensor.growatt_sph_load_power
    state_characteristic: standard_deviation
    max_age:
      hours: 1
  - platform: statistics
    name: "Home Electricity Power Standard Deviation Over A Day"
    unique_id: 3a0d219c-2dc3-4ef5-8964-23e739768499
    entity_id: sensor.growatt_sph_load_power
    state_characteristic: standard_deviation
    max_age:
      hours: 24
  - platform: statistics
    name: "Home Electricity Power Standard Deviation Over A Week"
    unique_id: c5a650f5-7d46-4918-a484-485831c7a922
    entity_id: sensor.growatt_sph_load_power
    state_characteristic: standard_deviation
    max_age:
      days: 7
  - platform: statistics
    name: "Home Electricity Power Standard Deviation Over A Month"
    unique_id: 15d61ca0-bf3f-4959-a526-bb4c5b9f851b
    entity_id: sensor.growatt_sph_load_power
    state_characteristic: standard_deviation
    max_age:
      days: 30
  # Boiler Flow
  - platform: statistics
    name: "Flow Temperature Delta Last 24 Hours"
    unique_id: 96bc7959-a867-4d5b-b733-188bcc25c92c
    entity_id: sensor.boiler_delta_temperature
    state_characteristic: mean
    max_age:
      hours: 24
  - platform: statistics
    name: "Flow Temperature Highest Delta"
    unique_id: aaac8076-2bfa-4f8d-825f-2603051f7eb9
    entity_id: sensor.boiler_delta_temperature
    state_characteristic: value_max
    sampling_size: 43200
    max_age:
      days: 30
  - platform: statistics
    name: "Flow Temperature Lowest Delta"
    unique_id: e4febfc7-2d8b-443d-8aae-b9d5d86e6449
    entity_id: sensor.boiler_delta_temperature
    state_characteristic: value_min
    sampling_size: 43200
    max_age:
      days: 30
  - platform: statistics
    name: "Flow Temperature Delta Difference"
    unique_id: 99a1f9d4-b8bb-456d-840a-e3ad0c997215
    entity_id: sensor.boiler_delta_temperature
    state_characteristic: distance_absolute
    sampling_size: 43200
    max_age:
      days: 30

to4ko · 2024-05-04T11:27:15Z

@bdraco looks like your fix is working

more detailed last 48hrs - cpu temp got normalized around 60degC and CPU load normalized (little build up and drop at 12^36 to be invetigated deeper)

bdraco · 2024-05-04T11:46:22Z

There's still a lot to be optimized in this integration, but to be honest, that's very hard to do without access to a system that's experiencing the issue that I could do live debugging on and rapidly iterate as otherwise I'm optimizing for theoretical use cases instead of practical ones

ayavilevich · 2024-05-04T19:50:01Z

@to4ko @dannytsang @myromeo Are you using the default sqlite database for recorder or do you have something custom like MariaDB or mysql?

myromeo · 2024-05-04T19:51:22Z

@ayavilevich i use the default SQLite.

dannytsang · 2024-05-04T19:54:45Z

@ayavilevich MySQL

ayavilevich · 2024-05-04T20:02:46Z

I've not had any luck replicating the problem.

Can you post your config for statistics?

Attaching my "platform: statistics" entries. Is "platform: history_stats" relevant as well?
What about automatic statistics that are generated for the metrics? At "http://server/developer-tools/statistics"
Please note that it takes it about 12 hours to ramp up to 100% CPU utilization. As if there is a "CPU leak". So it may be difficult to see this right away.

sensor:
  - platform: statistics
    name: "Pumps Current Mean 10m"
    entity_id: sensor.pumps_current
    state_characteristic: mean
    max_age:
      minutes: 10
  - platform: statistics
    name: "Pumps Current Mean 1d"
    entity_id: sensor.pumps_current
    state_characteristic: mean
    max_age:
      hours: 24
  - platform: statistics
    name: "Clouds mean 8h"
    entity_id: sensor.openweathermap_cloud_coverage
    state_characteristic: mean
    max_age:
      hours: 8
  - platform: statistics
    name: "Wind mean"
    entity_id: sensor.tasmota_wind_analog_range1
    state_characteristic: mean
    max_age:
      minutes: 5
  - platform: statistics
    name: "Wind mean 15m"
    entity_id: sensor.tasmota_wind_analog_range1
    state_characteristic: mean
    max_age:
      minutes: 15
  - platform: statistics
    name: "Wind mean 10m"
    entity_id: sensor.tasmota_wind_analog_range1
    state_characteristic: mean
    max_age:
      minutes: 10
  - platform: statistics
    name: "Wind mean 30m"
    entity_id: sensor.tasmota_wind_analog_range1
    state_characteristic: mean
    max_age:
      minutes: 30
  - platform: statistics
    name: "Wind mean 30s"
    entity_id: sensor.tasmota_wind_analog_range1
    state_characteristic: mean
    max_age:
      seconds: 30
  - platform: statistics
    name: "Wind median"
    entity_id: sensor.tasmota_wind_analog_range1
    state_characteristic: median
    max_age:
      minutes: 5
  - platform: statistics
    name: "Wind min"
    entity_id: sensor.tasmota_wind_analog_range1
    state_characteristic: value_min
    max_age:
      minutes: 5
  - platform: statistics
    name: "Wind max"
    entity_id: sensor.tasmota_wind_analog_range1
    state_characteristic: value_max
    max_age:
      minutes: 5
  - platform: statistics
    name: "Clouds mean 8h"
    entity_id: sensor.openweathermap_cloud_coverage
    state_characteristic: mean
    max_age:
      hours: 8

myromeo · 2024-05-04T20:08:38Z

Here are my statistics sensors too, fwiw.

`# Calculate 90 day average CGM

platform: statistics
name: 'Glucose Avg 90d'
unique_id: "glucose_90d_avg"
entity_id: sensor.glucose_value
state_characteristic: mean
precision: 3
max_age:
days: 90

Electricity demand stats - 24 hour period

platform: statistics
name: "Elec Average kWh"
entity_id: sensor.smart_electricity_meter_whole_home_power
state_characteristic: mean
precision: 3
max_age:
hours: 24
platform: statistics
name: "Elec Min kWh"
entity_id: sensor.smart_electricity_meter_whole_home_power
state_characteristic: value_min
precision: 3
max_age:
hours: 24
platform: statistics
name: "Elec Max kWh"
entity_id: sensor.smart_electricity_meter_whole_home_power
state_characteristic: value_max
precision: 3
max_age:
hours: 24

House Temperature (Living Room) stats - 24 hour period

platform: statistics
name: "livingroom_temp_ave"
entity_id: sensor.livingroom_temp
state_characteristic: mean
precision: 3
max_age:
hours: 24
platform: statistics
name: "livingroom_temp_min"
entity_id: sensor.livingroom_temp
state_characteristic: value_min
precision: 3
max_age:
hours: 24
platform: statistics
name: "livingroom_temp_max"
entity_id: sensor.livingroom_temp
state_characteristic: value_max
precision: 3
max_age:
hours: 24
`

to4ko · 2024-05-04T20:27:43Z

@to4ko @dannytsang @myromeo Are you using the default sqlite database for recorder or do you have something custom like MariaDB or mysql?

default SQLite

dannytsang · 2024-05-04T22:33:49Z

#116743 should eliminate the chance of a race unless there is a bug in the time calculation.

Can be tested with
cd /config
curl -o- -sSL https://gist.githubusercontent.com/bdraco/43f8043cb04b9838383fd71353e99b18/raw/core_integration_pr | bash /dev/stdin -d statistics -p 116743

This has definitely improved my setup. Thanks @bdraco

churchofnoise · 2024-05-05T06:28:49Z

#116743 should eliminate the chance of a race unless there is a bug in the time calculation.

Can be tested with
cd /config
curl -o- -sSL https://gist.githubusercontent.com/bdraco/43f8043cb04b9838383fd71353e99b18/raw/core_integration_pr | bash /dev/stdin -d statistics -p 116743

Seems to work here too, thank you!

myromeo · 2024-05-05T15:31:07Z

Also looking good here, nice work.

bdraco · 2024-05-05T21:54:34Z

Be sure to delete the custom version before updating to 2024.5.2

to4ko · 2024-05-06T05:19:39Z

Be sure to delete the custom version before updating to 2024.5.2

Should statistics folder be deleted totally or just statistics.py? Please advise for dumb-and-dumber:)

dannytsang · 2024-05-06T06:29:04Z

Folder.

bdraco added the needs-more-information label May 3, 2024

bdraco added the integration: statistics label May 3, 2024

dannytsang mentioned this issue May 3, 2024

Sluggish Performance On 2024.5 with statistics #116731

Closed

bdraco changed the title ~~2024.5.0 causing increased CPU usage and high temps~~ statistics on 2024.5.0 causing increased CPU usage and high temps May 3, 2024

bdraco mentioned this issue May 4, 2024

Refactor statistics to avoid creating tasks #116743

Merged

20 tasks

garry0garry mentioned this issue May 4, 2024

Automatically deactivate the ping sensor if the host is unavailable. Where is the logic? #116751

Open

balloob closed this as completed in #116743 May 5, 2024

github-actions bot locked and limited conversation to collaborators Jun 5, 2024

statistics on 2024.5.0 causing increased CPU usage and high temps #116650

statistics on 2024.5.0 causing increased CPU usage and high temps #116650

Comments

myromeo commented May 2, 2024

The problem

What version of Home Assistant Core has the issue?

What was the last working version of Home Assistant Core?

What type of installation are you running?

Integration causing the issue

Link to integration documentation on our website

Diagnostics information

Example YAML snippet

Anything in the logs that might be useful for us?

Additional information

bdraco commented May 2, 2024 • edited

nijel commented May 3, 2024

home-assistant bot commented May 3, 2024

bdraco commented May 3, 2024

bdraco commented May 3, 2024

nijel commented May 3, 2024

bdraco commented May 3, 2024 • edited

bdraco commented May 3, 2024

nijel commented May 3, 2024 • edited

ayavilevich commented May 3, 2024

bdraco commented May 3, 2024

myromeo commented May 3, 2024

ayavilevich commented May 3, 2024 • edited

ThomDietrich commented May 3, 2024

bdraco commented May 3, 2024

myromeo commented May 3, 2024

bdraco commented May 3, 2024

bdraco commented May 3, 2024

bdraco commented May 3, 2024

bdraco commented May 3, 2024

bdraco commented May 3, 2024

myromeo commented May 3, 2024

ayavilevich commented May 3, 2024

bdraco commented May 3, 2024

dannytsang commented May 3, 2024

bdraco commented May 3, 2024

bdraco commented May 3, 2024

bdraco commented May 4, 2024

bdraco commented May 4, 2024

to4ko commented May 4, 2024

dannytsang commented May 4, 2024

to4ko commented May 4, 2024

bdraco commented May 4, 2024 • edited

ayavilevich commented May 4, 2024

myromeo commented May 4, 2024

dannytsang commented May 4, 2024

ayavilevich commented May 4, 2024

myromeo commented May 4, 2024

Electricity demand stats - 24 hour period

House Temperature (Living Room) stats - 24 hour period

to4ko commented May 4, 2024

dannytsang commented May 4, 2024

churchofnoise commented May 5, 2024

myromeo commented May 5, 2024

bdraco commented May 5, 2024

to4ko commented May 6, 2024

dannytsang commented May 6, 2024

bdraco commented May 2, 2024 •

edited

bdraco commented May 3, 2024 •

edited

nijel commented May 3, 2024 •

edited

ayavilevich commented May 3, 2024 •

edited

bdraco commented May 4, 2024 •

edited