core: Ultraslow logbook queries when context ids have low cardinality

The problem

After upgrading to 2023.4.4 logbook database queries are terribly slow. The sensor history graphs are fast, but the logbooks needs minutes to appear. Queries like the following are running in the background. This one is quite fast, as it requires only 39 seconds, but some other entities logbooks appear only after waiting minutes.

I think many instances are affected with this problem:

WITH anon_1 AS 
        (SELECT anon_2.context_id_bin AS context_id_bin 
        FROM (SELECT events.context_id_bin AS context_id_bin 
        FROM events LEFT OUTER JOIN event_types ON events.event_type_id = event_types.event_type_id LEFT OUTER JOIN event_data ON events.data_id = event_data.data_id 
        WHERE events.time_fired_ts > 1681587500.67 AND events.time_fired_ts < 1681673900.677599 AND events.event_type_id IN (SELECT event_types.event_type_id 
        FROM event_types 
        WHERE event_types.event_type IN ('automation_triggered', 'logbook_entry', 'script_started')) AND ((CAST(event_data.shared_data AS JSONB) -> 'entity_id') IS NOT NULL AND CAST((CAST(event_data.shared_data AS JSONB) -> 'entity_id') AS TEXT) IN ('"person.xy"') OR (CAST(events.event_data AS JSONB) -> 'entity_id') IS NOT NULL AND CAST((CAST(events.event_data AS JSONB) -> 'entity_id') AS TEXT) IN ('"person.xy"')) UNION ALL SELECT states.context_id_bin AS context_id_bin 
        FROM states 
        WHERE states.last_updated_ts > 1681587500.67 AND states.last_updated_ts < 1681673900.677599 AND states.metadata_id IN (275)) AS anon_2 GROUP BY anon_2.context_id_bin)
         SELECT events.event_id AS event_id, event_types.event_type AS event_type, events.event_data AS event_data, events.time_fired_ts AS time_fired_ts, events.context_id_bin AS context_id_bin, events.context_user_id_bin AS context_user_id_bin, events.context_parent_id_bin AS context_parent_id_bin, event_data.shared_data AS shared_data, 0 AS state_id, NULL AS state, NULL AS entity_id, NULL AS icon, NULL AS old_format_icon, NULL AS context_only 
        FROM events LEFT OUTER JOIN event_types ON events.event_type_id = event_types.event_type_id LEFT OUTER JOIN event_data ON events.data_id = event_data.data_id 
        WHERE events.time_fired_ts > 1681587500.67 AND events.time_fired_ts < 1681673900.677599 AND events.event_type_id IN (SELECT event_types.event_type_id 
        FROM event_types 
        WHERE event_types.event_type IN ('automation_triggered', 'logbook_entry', 'script_started')) AND ((CAST(event_data.shared_data AS JSONB) -> 'entity_id') IS NOT NULL AND CAST((CAST(event_data.shared_data AS JSONB) -> 'entity_id') AS TEXT) IN ('"person.xy"') OR (CAST(events.event_data AS JSONB) -> 'entity_id') IS NOT NULL AND CAST((CAST(events.event_data AS JSONB) -> 'entity_id') AS TEXT) IN ('"person.xy"')) UNION ALL SELECT NULL AS event_id, NULL AS event_type, NULL AS event_data, states.last_updated_ts AS time_fired_ts, states.context_id_bin AS context_id_bin, states.context_user_id_bin AS context_user_id_bin, states.context_parent_id_bin AS context_parent_id_bin, NULL AS shared_data, states.state_id AS state_id, states.state AS state, states_meta.entity_id AS entity_id, CAST(CAST(state_attributes.shared_attrs AS JSON) ->> 'icon' AS VARCHAR) AS icon, CAST(CAST(states.attributes AS JSON) ->> 'icon' AS VARCHAR) AS old_format_icon, NULL AS context_only 
        FROM states LEFT OUTER JOIN states AS old_state ON states.old_state_id = old_state.state_id LEFT OUTER JOIN state_attributes ON states.attributes_id = state_attributes.attributes_id LEFT OUTER JOIN states_meta ON states.metadata_id = states_meta.metadata_id 
        WHERE states.last_updated_ts > 1681587500.67 AND states.last_updated_ts < 1681673900.677599 AND old_state.state_id IS NOT NULL AND states.state != old_state.state AND states.state IS NOT NULL AND ((states_meta.entity_id NOT LIKE 'proximity.%' AND states_meta.entity_id NOT LIKE 'counter.%' AND states_meta.entity_id NOT LIKE 'sensor.%') OR ((states_meta.entity_id LIKE 'sensor.%') AND (state_attributes.shared_attrs NOT LIKE '%"unit_of_measurement":%' OR states.attributes NOT LIKE '%"unit_of_measurement":%'))) AND (states.last_updated_ts = states.last_changed_ts OR states.last_changed_ts IS NULL) AND states.metadata_id IN (275) UNION ALL SELECT events.event_id AS event_id, event_types.event_type AS event_type, events.event_data AS event_data, events.time_fired_ts AS time_fired_ts, events.context_id_bin AS context_id_bin, events.context_user_id_bin AS context_user_id_bin, events.context_parent_id_bin AS context_parent_id_bin, event_data.shared_data AS shared_data, 0 AS state_id, NULL AS state, NULL AS entity_id, NULL AS icon, NULL AS old_format_icon, '1' AS context_only 
        FROM anon_1 LEFT OUTER JOIN events ON anon_1.context_id_bin = events.context_id_bin LEFT OUTER JOIN event_types ON events.event_type_id = event_types.event_type_id LEFT OUTER JOIN event_data ON events.data_id = event_data.data_id UNION ALL SELECT NULL AS event_id, NULL AS event_type, NULL AS event_data, states.last_updated_ts AS time_fired_ts, states.context_id_bin AS context_id_bin, states.context_user_id_bin AS context_user_id_bin, states.context_parent_id_bin AS context_parent_id_bin, NULL AS shared_data, states.state_id AS state_id, states.state AS state, states_meta.entity_id AS entity_id, NULL AS icon, NULL AS old_format_icon, '1' AS context_only 
        FROM anon_1 LEFT OUTER JOIN states ON anon_1.context_id_bin = states.context_id_bin LEFT OUTER JOIN states_meta ON states.metadata_id = states_meta.metadata_id ORDER BY time_fired_ts;

What version of Home Assistant Core has the issue?

2023.4.4

What was the last working version of Home Assistant Core?

2021.x.x

What type of installation are you running?

Home Assistant Core

Integration causing the issue

No response

Link to integration documentation on our website

No response

Diagnostics information

PostgreSQL 15. The database migration part of the upgrade is over. The database is big (6 years of data), but was fast with version 2021.x.x

Example YAML snippet

No response

Anything in the logs that might be useful for us?

No response

Additional information

No response

About this issue

  • Original URL
  • State: closed
  • Created a year ago
  • Reactions: 1
  • Comments: 61 (30 by maintainers)

Commits related to this issue

Most upvoted comments

Thank you very much for the constant support.

Can I leave my database as is with these random context_ids? I don’t know what’s the purpose of this column, but I can see entity history and logbook items in the UI from the past years too instantly.

They link events together to find the trigger in the logbook. The random data is likely just fine in the db. I’ll adjust the migration so we create a fresh ULID instead of empty bytes so others don’t have the district distribution issue if they are migrating for large data sets.

Its what is used for figuring out that the switch you pressed in HA turned on the light. They have decreasing value over time as its unlikely you need to know which user turned on a light 3 years ago 😃

+1
bdraco on Apr 19, 2023

Almost midnight here so I’ll check back in the morning. Good luck

+1
bdraco on Apr 19, 2023

How can I do this on my side ? restore a 2023.3 and migrate again ? or is there a cli command to “run” the migration somewhere ?

Disconnect the DB from HA by changing configuration.yaml Downgrade HA to 2023.3.x Restore your database from backup when it was in 2023.3.x format Fix any schema problems Restart HA with it pointing to your db in your configuration.yaml Upgrade to 2023.4.5

+1
bdraco on Apr 18, 2023

after all the metadata_id are set on the states table it will go back and clear the entity_id field

+1
bdraco on Apr 18, 2023

All the entity_ids should be null now. entity_ids are stored in states_meta now.

+1
bdraco on Apr 18, 2023

Once you have the schema corrected if the query is still slow please post an explain on it and we will try to optimize it.

+1
bdraco on Apr 17, 2023

I think foreign keys are at least missing on my events table to event_types and event_data tables:

                                               Table "public.events"
        Column         |           Type           | Collation | Nullable |                 Default                  
-----------------------+--------------------------+-----------+----------+------------------------------------------
 event_id              | integer                  |           | not null | nextval('events_event_id_seq'::regclass)
 event_type            | character varying(64)    |           |          | 
 event_data            | text                     |           |          | 
 origin                | character varying(32)    |           |          | 
 time_fired            | timestamp with time zone |           |          | 
 created               | timestamp with time zone |           |          | 
 context_id            | character(36)            |           |          | 
 context_user_id       | character(36)            |           |          | 
 context_parent_id     | character(36)            |           |          | 
 data_id               | integer                  |           |          | 
 origin_idx            | integer                  |           |          | 
 time_fired_ts         | double precision         |           |          | 
 context_id_bin        | bytea                    |           |          | 
 context_user_id_bin   | bytea                    |           |          | 
 context_parent_id_bin | bytea                    |           |          | 
 event_type_id         | integer                  |           |          | 
Indexes:
    "events_pkey" PRIMARY KEY, btree (event_id)
    "ix_events_context_id_bin" btree (context_id_bin)
    "ix_events_data_id" btree (data_id)
    "ix_events_event_type_id_time_fired_ts" btree (event_type_id, time_fired_ts)
    "ix_events_time_fired_ts" btree (time_fired_ts)
Referenced by:
    TABLE "states" CONSTRAINT "states_event_id_fkey" FOREIGN KEY (event_id) REFERENCES events(event_id) ON DELETE CASCADE
+1
terba on Apr 16, 2023

Here are mine (PostgreSQL). As I see I have one more index (ix_states_event_id) on states than you have:

       tablename       |                   indexname                    |                                                                indexdef                                                                
-----------------------+------------------------------------------------+----------------------------------------------------------------------------------------------------------------------------------------
 event_data            | event_data_pkey                                | CREATE UNIQUE INDEX event_data_pkey ON public.event_data USING btree (data_id)
 event_data            | ix_event_data_hash                             | CREATE INDEX ix_event_data_hash ON public.event_data USING btree (hash)
 event_types           | event_types_pkey                               | CREATE UNIQUE INDEX event_types_pkey ON public.event_types USING btree (event_type_id)
 event_types           | ix_event_types_event_type                      | CREATE UNIQUE INDEX ix_event_types_event_type ON public.event_types USING btree (event_type)
 events                | events_pkey                                    | CREATE UNIQUE INDEX events_pkey ON public.events USING btree (event_id)
 events                | ix_events_context_id_bin                       | CREATE INDEX ix_events_context_id_bin ON public.events USING btree (context_id_bin)
 events                | ix_events_data_id                              | CREATE INDEX ix_events_data_id ON public.events USING btree (data_id)
 events                | ix_events_event_type_id_time_fired_ts          | CREATE INDEX ix_events_event_type_id_time_fired_ts ON public.events USING btree (event_type_id, time_fired_ts)
 events                | ix_events_time_fired_ts                        | CREATE INDEX ix_events_time_fired_ts ON public.events USING btree (time_fired_ts)
 recorder_runs         | ix_recorder_runs_start_end                     | CREATE INDEX ix_recorder_runs_start_end ON public.recorder_runs USING btree (start, "end")
 recorder_runs         | recorder_runs_pkey                             | CREATE UNIQUE INDEX recorder_runs_pkey ON public.recorder_runs USING btree (run_id)
 schema_changes        | schema_changes_pkey                            | CREATE UNIQUE INDEX schema_changes_pkey ON public.schema_changes USING btree (change_id)
 state_attributes      | ix_state_attributes_hash                       | CREATE INDEX ix_state_attributes_hash ON public.state_attributes USING btree (hash)
 state_attributes      | state_attributes_pkey                          | CREATE UNIQUE INDEX state_attributes_pkey ON public.state_attributes USING btree (attributes_id)
 states                | ix_states_attributes_id                        | CREATE INDEX ix_states_attributes_id ON public.states USING btree (attributes_id)
 states                | ix_states_context_id_bin                       | CREATE INDEX ix_states_context_id_bin ON public.states USING btree (context_id_bin)
 states                | ix_states_event_id                             | CREATE INDEX ix_states_event_id ON public.states USING btree (event_id)
 states                | ix_states_last_updated_ts                      | CREATE INDEX ix_states_last_updated_ts ON public.states USING btree (last_updated_ts)
 states                | ix_states_metadata_id_last_updated_ts          | CREATE INDEX ix_states_metadata_id_last_updated_ts ON public.states USING btree (metadata_id, last_updated_ts)
 states                | ix_states_old_state_id                         | CREATE INDEX ix_states_old_state_id ON public.states USING btree (old_state_id)
 states                | states_pkey                                    | CREATE UNIQUE INDEX states_pkey ON public.states USING btree (state_id)
 states_meta           | ix_states_meta_entity_id                       | CREATE UNIQUE INDEX ix_states_meta_entity_id ON public.states_meta USING btree (entity_id)
 states_meta           | states_meta_pkey                               | CREATE UNIQUE INDEX states_meta_pkey ON public.states_meta USING btree (metadata_id)
 statistics            | ix_statistics_start_ts                         | CREATE INDEX ix_statistics_start_ts ON public.statistics USING btree (start_ts)
 statistics            | ix_statistics_statistic_id_start_ts            | CREATE UNIQUE INDEX ix_statistics_statistic_id_start_ts ON public.statistics USING btree (metadata_id, start_ts)
 statistics            | statistics_pkey                                | CREATE UNIQUE INDEX statistics_pkey ON public.statistics USING btree (id)
 statistics_meta       | ix_statistics_meta_statistic_id                | CREATE UNIQUE INDEX ix_statistics_meta_statistic_id ON public.statistics_meta USING btree (statistic_id)
 statistics_meta       | statistics_meta_pkey                           | CREATE UNIQUE INDEX statistics_meta_pkey ON public.statistics_meta USING btree (id)
 statistics_runs       | ix_statistics_runs_start                       | CREATE INDEX ix_statistics_runs_start ON public.statistics_runs USING btree (start)
 statistics_runs       | statistics_runs_pkey                           | CREATE UNIQUE INDEX statistics_runs_pkey ON public.statistics_runs USING btree (run_id)
 statistics_short_term | ix_statistics_short_term_start_ts              | CREATE INDEX ix_statistics_short_term_start_ts ON public.statistics_short_term USING btree (start_ts)
 statistics_short_term | ix_statistics_short_term_statistic_id_start_ts | CREATE UNIQUE INDEX ix_statistics_short_term_statistic_id_start_ts ON public.statistics_short_term USING btree (metadata_id, start_ts)
 statistics_short_term | statistics_short_term_pkey                     | CREATE UNIQUE INDEX statistics_short_term_pkey ON public.statistics_short_term USING btree (id)
(33 rows)
+1
terba on Apr 16, 2023

I think the migration failed to create some indexes somewhere.

These are mine to compare :


SELECT DISTINCT
    TABLE_NAME,
    INDEX_NAME
FROM INFORMATION_SCHEMA.STATISTICS
WHERE TABLE_SCHEMA = 'homeassistant';


TABLE_NAME	INDEX_NAME	
event_data	PRIMARY	
event_data	ix_event_data_hash	
event_types	PRIMARY	
event_types	ix_event_types_event_type	
events	PRIMARY	
events	ix_events_data_id	
events	ix_events_time_fired_ts	
events	ix_events_context_id_bin	
events	ix_events_event_type_id_time_fired_ts	
recorder_runs	PRIMARY	
recorder_runs	ix_recorder_runs_start_end	
schema_changes	PRIMARY	
state_attributes	PRIMARY	
state_attributes	ix_state_attributes_hash	
states	PRIMARY	
states	ix_states_attributes_id	
states	ix_states_old_state_id	
states	ix_states_last_updated_ts	
states	ix_states_context_id_bin	
states	ix_states_metadata_id_last_updated_ts	
states_meta	PRIMARY	
states_meta	ix_states_meta_entity_id	
statistics	PRIMARY	
statistics	ix_statistics_statistic_id_start_ts	
statistics	ix_statistics_start_ts	
statistics_meta	PRIMARY	
statistics_meta	ix_statistics_meta_statistic_id	
statistics_runs	PRIMARY	
statistics_runs	ix_statistics_runs_start	
statistics_short_term	PRIMARY	
statistics_short_term	ix_statistics_short_term_statistic_id_start_ts	
statistics_short_term	ix_statistics_short_term_start_ts
+1
prigal on Apr 16, 2023
Read more comments on GitHub
← core: Ukraine Alarm - Unexpected error
core: unable setup huawei_lte →