Recorder logs error since 2025.1.0b0 #134002

luca-angemi · 2024-12-25T15:13:33Z

The problem

Since 2025.1.0b0 every night at 4.12 am these errors are showing up in the logs

2024-12-25 04:12:09.285 ERROR (Recorder) [homeassistant.helpers.recorder] Error executing query
Traceback (most recent call last):
  File "/usr/local/lib/python3.13/site-packages/sqlalchemy/engine/base.py", line 1967, in _exec_single_context
    self.dialect.do_execute(
    ~~~~~~~~~~~~~~~~~~~~~~~^
        cursor, str_statement, effective_parameters, context
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
    )
    ^
  File "/usr/local/lib/python3.13/site-packages/sqlalchemy/engine/default.py", line 941, in do_execute
    cursor.execute(statement, parameters)
    ~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^
sqlite3.IntegrityError: FOREIGN KEY constraint failed
The above exception was the direct cause of the following exception:
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/recorder.py", line 101, in session_scope
    yield session
  File "/usr/src/homeassistant/homeassistant/components/recorder/purge.py", line 121, in purge_old_data
    _purge_old_entity_ids(instance, session)
    ~~~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/recorder/purge.py", line 570, in _purge_old_entity_ids
    deleted_rows = session.execute(delete_states_meta_rows(states_metadata_ids))
  File "/usr/local/lib/python3.13/site-packages/sqlalchemy/orm/session.py", line 2362, in execute
    return self._execute_internal(
           ~~~~~~~~~~~~~~~~~~~~~~^
        statement,
        ^^^^^^^^^^
    ...<4 lines>...
        _add_event=_add_event,
        ^^^^^^^^^^^^^^^^^^^^^^
    )
    ^
  File "/usr/local/lib/python3.13/site-packages/sqlalchemy/orm/session.py", line 2247, in _execute_internal
    result: Result[Any] = compile_state_cls.orm_execute_statement(
                          ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~^
        self,
        ^^^^^
    ...<4 lines>...
        conn,
        ^^^^^
    )
    ^
  File "/usr/local/lib/python3.13/site-packages/sqlalchemy/orm/bulk_persistence.py", line 2021, in orm_execute_statement
    return super().orm_execute_statement(
           ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~^
        session, statement, params, execution_options, bind_arguments, conn
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
    )
    ^
  File "/usr/local/lib/python3.13/site-packages/sqlalchemy/orm/context.py", line 305, in orm_execute_statement
    result = conn.execute(
        statement, params or {}, execution_options=execution_options
    )
  File "/usr/local/lib/python3.13/site-packages/sqlalchemy/engine/base.py", line 1418, in execute
    return meth(
        self,
        distilled_parameters,
        execution_options or NO_OPTIONS,
    )
  File "/usr/local/lib/python3.13/site-packages/sqlalchemy/sql/lambdas.py", line 603, in _execute_on_connection
    return connection._execute_clauseelement(
           ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~^
        self, distilled_params, execution_options
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
    )
    ^
  File "/usr/local/lib/python3.13/site-packages/sqlalchemy/engine/base.py", line 1640, in _execute_clauseelement
    ret = self._execute_context(
        dialect,
    ...<8 lines>...
        cache_hit=cache_hit,
    )
  File "/usr/local/lib/python3.13/site-packages/sqlalchemy/engine/base.py", line 1846, in _execute_context
    return self._exec_single_context(
           ~~~~~~~~~~~~~~~~~~~~~~~~~^
        dialect, context, statement, parameters
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
    )
    ^
  File "/usr/local/lib/python3.13/site-packages/sqlalchemy/engine/base.py", line 1986, in _exec_single_context
    self._handle_dbapi_exception(
    ~~~~~~~~~~~~~~~~~~~~~~~~~~~~^
        e, str_statement, effective_parameters, cursor, context
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
    )
    ^
  File "/usr/local/lib/python3.13/site-packages/sqlalchemy/engine/base.py", line 2355, in _handle_dbapi_exception
    raise sqlalchemy_exception.with_traceback(exc_info[2]) from e
  File "/usr/local/lib/python3.13/site-packages/sqlalchemy/engine/base.py", line 1967, in _exec_single_context
    self.dialect.do_execute(
    ~~~~~~~~~~~~~~~~~~~~~~~^
        cursor, str_statement, effective_parameters, context
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
    )
    ^
  File "/usr/local/lib/python3.13/site-packages/sqlalchemy/engine/default.py", line 941, in do_execute
    cursor.execute(statement, parameters)
    ~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^
sqlalchemy.exc.IntegrityError: (sqlite3.IntegrityError) FOREIGN KEY constraint failed
[SQL: DELETE FROM states_meta WHERE states_meta.metadata_id IN (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)]
[parameters: (1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16, 17, 18, 19, 20, 21, 22, 23, 24, 25, 26, 27, 28, 29, 30, 31, 32, 33, 34, 35, 36, 37, 38, 39, 40, 41, 42, 43, 44, 45, 46, 47, 48, 49, 50 ... 174 parameters truncated ... 225, 226, 227, 228, 229, 230, 231, 232, 233, 234, 235, 236, 237, 238, 239, 240, 241, 242, 243, 244, 245, 246, 247, 248, 249, 250, 251, 252, 253, 254, 255, 256, 257, 258, 259, 260, 261, 271, 276, 277, 278, 279, 280, 281, 282, 283, 284, 285, 286, 1498)]
(Background on this error at: https://sqlalche.me/e/20/gkpj)
2024-12-25 04:12:09.307 ERROR (Recorder) [homeassistant.components.recorder.core] Unhandled database error while processing task PurgeTask(purge_before=datetime.datetime(2024, 12, 15, 3, 12, 0, 63282, tzinfo=datetime.timezone.utc), repack=False, apply_filter=False)
Traceback (most recent call last):
  File "/usr/local/lib/python3.13/site-packages/sqlalchemy/engine/base.py", line 1967, in _exec_single_context
    self.dialect.do_execute(
    ~~~~~~~~~~~~~~~~~~~~~~~^
        cursor, str_statement, effective_parameters, context
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
    )
    ^
  File "/usr/local/lib/python3.13/site-packages/sqlalchemy/engine/default.py", line 941, in do_execute
    cursor.execute(statement, parameters)
    ~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^
sqlite3.IntegrityError: FOREIGN KEY constraint failed
The above exception was the direct cause of the following exception:
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/recorder/core.py", line 882, in _process_one_task_or_event_or_recover
    task.run(self)
    ~~~~~~~~^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/recorder/tasks.py", line 120, in run
    if purge.purge_old_data(
       ~~~~~~~~~~~~~~~~~~~~^
        instance, self.purge_before, self.repack, self.apply_filter
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
    ):
    ^
  File "/usr/src/homeassistant/homeassistant/components/recorder/util.py", line 697, in wrapper
    return job(*args, **kwargs)
  File "/usr/src/homeassistant/homeassistant/components/recorder/purge.py", line 121, in purge_old_data
    _purge_old_entity_ids(instance, session)
    ~~~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/recorder/purge.py", line 570, in _purge_old_entity_ids
    deleted_rows = session.execute(delete_states_meta_rows(states_metadata_ids))
  File "/usr/local/lib/python3.13/site-packages/sqlalchemy/orm/session.py", line 2362, in execute
    return self._execute_internal(
           ~~~~~~~~~~~~~~~~~~~~~~^
        statement,
        ^^^^^^^^^^
    ...<4 lines>...
        _add_event=_add_event,
        ^^^^^^^^^^^^^^^^^^^^^^
    )
    ^
  File "/usr/local/lib/python3.13/site-packages/sqlalchemy/orm/session.py", line 2247, in _execute_internal
    result: Result[Any] = compile_state_cls.orm_execute_statement(
                          ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~^
        self,
        ^^^^^
    ...<4 lines>...
        conn,
        ^^^^^
    )
    ^
  File "/usr/local/lib/python3.13/site-packages/sqlalchemy/orm/bulk_persistence.py", line 2021, in orm_execute_statement
    return super().orm_execute_statement(
           ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~^
        session, statement, params, execution_options, bind_arguments, conn
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
    )
    ^
  File "/usr/local/lib/python3.13/site-packages/sqlalchemy/orm/context.py", line 305, in orm_execute_statement
    result = conn.execute(
        statement, params or {}, execution_options=execution_options
    )
  File "/usr/local/lib/python3.13/site-packages/sqlalchemy/engine/base.py", line 1418, in execute
    return meth(
        self,
        distilled_parameters,
        execution_options or NO_OPTIONS,
    )
  File "/usr/local/lib/python3.13/site-packages/sqlalchemy/sql/lambdas.py", line 603, in _execute_on_connection
    return connection._execute_clauseelement(
           ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~^
        self, distilled_params, execution_options
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
    )
    ^
  File "/usr/local/lib/python3.13/site-packages/sqlalchemy/engine/base.py", line 1640, in _execute_clauseelement
    ret = self._execute_context(
        dialect,
    ...<8 lines>...
        cache_hit=cache_hit,
    )
  File "/usr/local/lib/python3.13/site-packages/sqlalchemy/engine/base.py", line 1846, in _execute_context
    return self._exec_single_context(
           ~~~~~~~~~~~~~~~~~~~~~~~~~^
        dialect, context, statement, parameters
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
    )
    ^
  File "/usr/local/lib/python3.13/site-packages/sqlalchemy/engine/base.py", line 1986, in _exec_single_context
    self._handle_dbapi_exception(
    ~~~~~~~~~~~~~~~~~~~~~~~~~~~~^
        e, str_statement, effective_parameters, cursor, context
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
    )
    ^
  File "/usr/local/lib/python3.13/site-packages/sqlalchemy/engine/base.py", line 2355, in _handle_dbapi_exception
    raise sqlalchemy_exception.with_traceback(exc_info[2]) from e
  File "/usr/local/lib/python3.13/site-packages/sqlalchemy/engine/base.py", line 1967, in _exec_single_context
    self.dialect.do_execute(
    ~~~~~~~~~~~~~~~~~~~~~~~^
        cursor, str_statement, effective_parameters, context
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
    )
    ^
  File "/usr/local/lib/python3.13/site-packages/sqlalchemy/engine/default.py", line 941, in do_execute
    cursor.execute(statement, parameters)
    ~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^
sqlalchemy.exc.IntegrityError: (sqlite3.IntegrityError) FOREIGN KEY constraint failed
[SQL: DELETE FROM states_meta WHERE states_meta.metadata_id IN (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)]
[parameters: (1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16, 17, 18, 19, 20, 21, 22, 23, 24, 25, 26, 27, 28, 29, 30, 31, 32, 33, 34, 35, 36, 37, 38, 39, 40, 41, 42, 43, 44, 45, 46, 47, 48, 49, 50 ... 174 parameters truncated ... 225, 226, 227, 228, 229, 230, 231, 232, 233, 234, 235, 236, 237, 238, 239, 240, 241, 242, 243, 244, 245, 246, 247, 248, 249, 250, 251, 252, 253, 254, 255, 256, 257, 258, 259, 260, 261, 271, 276, 277, 278, 279, 280, 281, 282, 283, 284, 285, 286, 1498)]
(Background on this error at: https://sqlalche.me/e/20/gkpj)

What version of Home Assistant Core has the issue?

2025.1.0b0

What was the last working version of Home Assistant Core?

2024.12

What type of installation are you running?

Home Assistant OS

Integration causing the issue

recorder

Link to integration documentation on our website

https://www.home-assistant.io/integrations/recorder/

Diagnostics information

No response

Example YAML snippet

No response

Anything in the logs that might be useful for us?

No response

Additional information

No response

The text was updated successfully, but these errors were encountered:

home-assistant · 2024-12-25T15:13:36Z

Hey there @home-assistant/core, mind taking a look at this issue as it has been labeled with an integration (recorder) you are listed as a code owner for? Thanks!

Code owner commands

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

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

bdraco · 2024-12-25T17:57:32Z

@luca-angemi can you share the database to either my Dropbox [email protected] or gdrive [email protected]?

luca-angemi · 2024-12-25T18:04:10Z

Done. Zipped and shared on gdrive.

bdraco · 2024-12-25T18:18:41Z

The cause is some un-migrated rows from 2023-01-25 that still exist in the database that have an attributes_id and metadata_id but a NULL last_updated_ts

bdraco · 2024-12-25T18:20:21Z

Was there a chance that Home Assistant was downgraded to an earlier version with this database in place after the migration took place?

luca-angemi · 2024-12-25T18:22:38Z

I'm going to check the realese notes for Jan/Feb 2023 in case I remember something, but I doubt I ever downgraded.

bdraco · 2024-12-25T18:23:13Z

On a sidenote, this data can't be purged because there's no way to index it. So this has been a problem for a very long time.

luca-angemi · 2024-12-25T18:24:13Z

So I'll have those errors every day from now on?
Not even a custom SQL script can fix it?

bdraco · 2024-12-25T18:25:22Z

Its pretty easy to migrate manually if thats what it comes to. I'd really like to figure out how it was even possible for those rows to be missed as I've looked at the queries and I can't find a way. The only thing I can think of is they were added after the migration was done

luca-angemi · 2024-12-25T18:26:22Z

I can only see this related to DB in 2023.2 #84870

luca-angemi · 2024-12-25T18:32:10Z

I don't remember downgrading but 2023-1-25 was the first beta day of 2023.2 so it could have happened.

fixes #134002

home-assistant bot added the integration: recorder label Dec 25, 2024

balloob assigned bdraco Dec 25, 2024

frenck added this to the 2025.1.0 milestone Dec 25, 2024

bdraco added a commit that referenced this issue Dec 25, 2024

Ensure all states have been migrated to use timestamps

023135d

fixes #134002

bdraco mentioned this issue Dec 25, 2024

Ensure all states have been migrated to use timestamps #134007

Merged

19 tasks

bdraco closed this as completed in #134007 Dec 26, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Recorder logs error since 2025.1.0b0 #134002

Recorder logs error since 2025.1.0b0 #134002

luca-angemi commented Dec 25, 2024

home-assistant bot commented Dec 25, 2024

bdraco commented Dec 25, 2024

luca-angemi commented Dec 25, 2024

bdraco commented Dec 25, 2024

bdraco commented Dec 25, 2024

luca-angemi commented Dec 25, 2024

bdraco commented Dec 25, 2024

luca-angemi commented Dec 25, 2024

bdraco commented Dec 25, 2024

luca-angemi commented Dec 25, 2024

luca-angemi commented Dec 25, 2024 •

edited

Loading

Recorder logs error since 2025.1.0b0 #134002

Recorder logs error since 2025.1.0b0 #134002

Comments

luca-angemi commented Dec 25, 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

home-assistant bot commented Dec 25, 2024

bdraco commented Dec 25, 2024

luca-angemi commented Dec 25, 2024

bdraco commented Dec 25, 2024

bdraco commented Dec 25, 2024

luca-angemi commented Dec 25, 2024

bdraco commented Dec 25, 2024

luca-angemi commented Dec 25, 2024

bdraco commented Dec 25, 2024

luca-angemi commented Dec 25, 2024

luca-angemi commented Dec 25, 2024 • edited Loading

luca-angemi commented Dec 25, 2024 •

edited

Loading