Reducing loading time for Logbook/History b

[Sebex]

Hi all,

I am experiencing very slow load times when accessing the Logbook or History tabs in HA and I am looking for ways to improve this (I am using a RPI 3B+ running HA on docker).
I came across this topic which seemed to address my problem but it appeared to be a different cause.

The reason why loading Logbook / History is slow is due to that 25500 rows are used to render the page (see below). Is there anyway to minimise the amount of rows used to render to reduce loading time?
Any suggestions are welcome!

2020-02-09 20:13:18 DEBUG (SyncWorker_14) [homeassistant.components.recorder.util] converting 1 rows to native objects took 0.078752s
2020-02-09 20:13:18 DEBUG (SyncWorker_14) [homeassistant.components.history] getting 1 first datapoints took 0.174754s
2020-02-09 20:13:19 DEBUG (MainThread) [homeassistant.components.history] Extracted 5756 states in 18.286318s
2020-02-09 20:13:19 DEBUG (SyncWorker_17) [homeassistant.components.recorder.util] converting 5760 rows to native objects took 18.791389s
2020-02-09 20:13:19 DEBUG (SyncWorker_17) [homeassistant.components.history] get_significant_states took 18.923634s
2020-02-09 20:13:19 DEBUG (SyncWorker_17) [homeassistant.components.recorder.util] converting 1 rows to native objects took 0.067947s
2020-02-09 20:13:19 DEBUG (SyncWorker_17) [homeassistant.components.history] getting 1 first datapoints took 0.171320s
2020-02-09 20:13:20 DEBUG (MainThread) [homeassistant.components.history] Extracted 5761 states in 19.448704s
2020-02-09 20:13:49 DEBUG (SyncWorker_12) [homeassistant.components.recorder.util] converting 14473 rows to native objects took 20.091915s
2020-02-09 20:13:50 DEBUG (SyncWorker_12) [homeassistant.components.history] get_significant_states took 20.106214s
2020-02-09 20:13:50 DEBUG (SyncWorker_12) [homeassistant.components.recorder.util] converting 1 rows to native objects took 0.020867s
2020-02-09 20:13:50 DEBUG (SyncWorker_12) [homeassistant.components.history] getting 1 first datapoints took 0.058466s
2020-02-09 20:13:50 DEBUG (MainThread) [homeassistant.components.history] Extracted 14474 states in 20.440697s
2020-02-09 20:14:25 DEBUG (SyncWorker_15) [homeassistant.components.recorder.util] converting 25500 rows to native objects took 35.942505s
2020-02-09 20:14:25 DEBUG (SyncWorker_15) [homeassistant.components.history] get_significant_states took 36.045067s
2020-02-09 20:14:26 DEBUG (SyncWorker_15) [homeassistant.components.recorder.util] converting 7 rows to native objects took 1.125338s
2020-02-09 20:14:26 DEBUG (SyncWorker_15) [homeassistant.components.history] getting 7 first datapoints took 1.176136s
2020-02-09 20:14:27 DEBUG (MainThread) [homeassistant.components.history] Extracted 25507 states in 38.117463s

[paulstronaut (Paul)]

It’s less about the number of rows to render and more about the lookup from the database. Take a look at things like get_significant_states took 20.106214s.

Your best option is to move the recorder to another platform because the default, SQLite has pretty poor performance as it grows in size. https://www.home-assistant.io/integrations/recorder/. I push my data to a MariaDB instance on a shared server. The logbook and history panels each take less than 3 seconds to fully load and render 100s of entities worth of data

[Sebex]

It’s less about the number of rows to render and more about the lookup from the database. Take a look at things like get_significant_states took 20.106214s .
Your best option is to move the recorder to another platform because the default, SQLite has pretty poor performance as it grows in size. https://www.home-assistant.io/integrations/recorder/ . I push my data to a MariaDB instance on a shared server. The logbook and history panels each take less than 3 seconds to fully load and render 100s of entities worth of data

Ok, interesting. On the topic I linked (see below) a community member mentioned that it’s not due to the database. Together with your answer I’m a bit lost now… is it due to database or Python query?

(SOLVED) Performance of history data is extremely slow

This is the key to understanding where the problem is. 36 out of the 38 seconds is taken up in Python code, not database access! This means that the query is fine from a raw query performance perspective and the issue has nothing to do with read speed, SD cards, etc. This is entirely CPU-bound number-crunching work. There’s definitely a need to rethink how history data is stored and subsequently queried as a huge number of those 25500 rows are not needed to actually render the page. But don’t …

[OverloadUT (Allie Laabs)]

Sebex is correct here. The log timings have some supersets in them.

get_significant_states took 36.045067s is INCLUDING converting 25500 rows to native objects took 35.942505s as part of its timing. So as you can see, the vast vast majority of the overall time is spend in converting the database data to Python objects.

Changing your recorder engine will not improve this timing.

[maxym]

Well… recklessness of today’s programmers. I can see it almost every day. They really don’t care about data. Most important is to make programming easy: lets serialize/deserialize objects directly to database. Even better: use ORM and 3rd party components which makes traversing data even easier.
It works with 10 records on the table, so it will with millions. Sure…

[OverloadUT (Allie Laabs)]

Here’s a bit more detail. For context, I am the one who re-wrote the queries in the history component and fixed them from taking dozens of minutes to less than a second. But I am only talking about the _ database queries_, not the overall performance of the API call end-to-end.

So let’s talk about that end-to-end: get_significant_states is the big method that gets all of the records needed to render graphs. It is the entirety of the API call, more or less. It does a few things:

1. It runs two queries to the database. These queries are VERY fast, even on SQLite, even with a ton of entries.
2. Then it sends this raw query result data to recorder.util to process the query results in to a format that Python can work with. This is what the converting XXXXX rows to native objects debug line is referring to.
3. It then sends all of the rows, now nicely organized in to a JSON response, out to whoever called the API.

Outside of the method, but worth mentioning:
4. The web browser now takes this massive json and uses it to render a ton of graphs. There is a big performance hit here, as the browser is having to work with tens of thousands of datapoints, and TONS of them are redundant for what it actually needs to render a graph.

I actually added profiling code to investigate this issue a year or so back, and got very granular data about what is taking time in the “converting objects” phase. The problem is I didn’t see any easy wins to make the code go faster. My tentative proposed solution now is that we need a whole new DB table that stores just the data for history graphs, which would be a subset of the data that is in the states table. We could then tailor that data to exactly what the history page needs.

[AhmadK (akasma74)]

It would be great if you guys could improve the logbook/recorder performance (afaik the latter is the real issue).
If you just want to have more responsive logbook, a custom component does exist.

[Sebex]

@OverloadUT thanks for the detailed explanation, I hope it’s something that can be part of a future release.

[arontsang]

I’ve asked the devs to improve performance by switching to Pypy instead of CPython, but they ignored my request.

[arontsang]

A simple 1 hour piece of work involving reading the source code and stackoverflowing yields a single line change that increase performance by orders of magnitude. This is really stupid how bad this is.

Python 2.6 JSON decoding performance

Simply replacing

homeassistant/components/recorder/models.py:3

import json

to

import simplejson as json

And also pulling the simplejson package from pypi, yields much better performance.

I have a PR for merging my changes here https://github.com/home-assistant/core/pull/35081

There is the potential to add an

loop.run_until_complete(asyncio.gather(rows.map(r -> r.to_native)))

If I can figure out how to access the executors from recorder utils. That would give us a multicore speed boost on the deserialization.

[Tamadite (jesuschal)]

What about using a non-SQL database like MongoDB? Would it shortcut the procedure of getting a JSON response from the source as well as introducing flexible data schemas?

[jeremyc (Jeremy Cook)]

I have had the same problem with unresponsive HA and slow retrieval of history, even to the extent of needing to restart HA without inderstanding why. I figured out in the end that the problems were caused because of high frequency updates and recording of real-time energy data and the dependent template sensors. You can read how I solved this in my project post here:

Energy metering and load balancing

Hi there, I have now reached a point of “almost finished” with my energy meter and energy load balancing project and it’s time to share my findings and configuration. Despite this being apparently a simple configuration, there were a number of challenges along the way and this article shows how I solved those. For example my home-assistant became unresponsive at one stage just by adding a new sensor. In this project thread (there will be more than one post over a few days) I will tell: How to…

Now my history graphs are responsive and shown quickly.