home-assistant / core

:house_with_garden: Open source home automation that puts local control and privacy first.
https://www.home-assistant.io
Apache License 2.0
73.74k stars 30.86k forks source link

DB migration: "Could not update foreign options in states table" #123221

Open LaStrada opened 3 months ago

LaStrada commented 3 months ago

The problem

I got this error after about 8 hours of migration. 10 min later I got:

Source: components/recorder/migration.py:307
integration: Recorder (documentation, issues)
First occurred: 07:41:27 (1 occurrences)
Last logged: 07:41:27

Upgrade to version 44 done

so it seems like it succeeded, so I'm not sure what this error actually means. This is the first 2024.8 beta I've installed.

What version of Home Assistant Core has the issue?

core-2024.8.0b3

What was the last working version of Home Assistant Core?

core-2024.7.x

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?

Logger: homeassistant.components.recorder.migration
Source: components/recorder/migration.py:694
integration: Recorder (documentation, issues)
First occurred: 07:31:57 (1 occurrences)
Last logged: 07:31:57

Could not update foreign options in states table
Traceback (most recent call last):
  File "/usr/local/lib/python3.12/site-packages/sqlalchemy/engine/base.py", line 1967, in _exec_single_context
    self.dialect.do_execute(
  File "/usr/local/lib/python3.12/site-packages/sqlalchemy/engine/default.py", line 924, in do_execute
    cursor.execute(statement, parameters)
  File "/usr/local/lib/python3.12/site-packages/MySQLdb/cursors.py", line 179, in execute
    res = self._query(mogrified_query)
          ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/MySQLdb/cursors.py", line 330, in _query
    db.query(q)
  File "/usr/local/lib/python3.12/site-packages/MySQLdb/connections.py", line 261, in query
    _mysql.connection.query(self, query)
MySQLdb.OperationalError: (1206, 'The total number of locks exceeds the lock table size')

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/recorder/migration.py", line 694, in _restore_foreign_key_constraints
    connection.execute(add_constraint)
  File "/usr/local/lib/python3.12/site-packages/sqlalchemy/engine/base.py", line 1418, in execute
    return meth(
           ^^^^^
  File "/usr/local/lib/python3.12/site-packages/sqlalchemy/sql/ddl.py", line 180, in _execute_on_connection
    return connection._execute_ddl(
           ^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/sqlalchemy/engine/base.py", line 1529, in _execute_ddl
    ret = self._execute_context(
          ^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/sqlalchemy/engine/base.py", line 1846, in _execute_context
    return self._exec_single_context(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/sqlalchemy/engine/base.py", line 1986, in _exec_single_context
    self._handle_dbapi_exception(
  File "/usr/local/lib/python3.12/site-packages/sqlalchemy/engine/base.py", line 2353, in _handle_dbapi_exception
    raise sqlalchemy_exception.with_traceback(exc_info[2]) from e
  File "/usr/local/lib/python3.12/site-packages/sqlalchemy/engine/base.py", line 1967, in _exec_single_context
    self.dialect.do_execute(
  File "/usr/local/lib/python3.12/site-packages/sqlalchemy/engine/default.py", line 924, in do_execute
    cursor.execute(statement, parameters)
  File "/usr/local/lib/python3.12/site-packages/MySQLdb/cursors.py", line 179, in execute
    res = self._query(mogrified_query)
          ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/MySQLdb/cursors.py", line 330, in _query
    db.query(q)
  File "/usr/local/lib/python3.12/site-packages/MySQLdb/connections.py", line 261, in query
    _mysql.connection.query(self, query)
sqlalchemy.exc.OperationalError: (MySQLdb.OperationalError) (1206, 'The total number of locks exceeds the lock table size')
[SQL: ALTER TABLE states ADD FOREIGN KEY(attributes_id) REFERENCES state_attributes (attributes_id)]
(Background on this error at: https://sqlalche.me/e/20/e3q8)

Additional information

I'm using the MariaDB v2.7.1 addon with this config:

db_url: mysql://username:password@core-mariadb/homeassistant?charset=utf8mb4
purge_keep_days: 360
db_max_retries: 360
db_retry_wait: 30

(yes I know the purge_keep_days should be way lower, but I needed statistics for close to a year for a few sensors. I've never had time to migrate those sensors to a different system)

home-assistant[bot] commented 3 months ago

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)

LaStrada commented 3 months ago

And just to clarify: The recorder seems to be working. As far as I can see, I didn't loose any data during this migration, and it's working after the migration.

bdraco commented 3 months ago

There is a retry wrapper around that function that will cause it to retry 10 times. It looks like it ran out of locks on the first try and was successful on another attempt.

emontnemery commented 3 months ago

@LaStrada way off-topic, but how come the built-in sensor statistics doesn't suffice?

emontnemery commented 3 months ago

@bdraco any idea why we're running out of locks?

LaStrada commented 3 months ago

@LaStrada way off-topic, but how come the built-in sensor statistics doesn't suffice?

Everything stopped working for about 8 hours, which was expected I guess. When the migration was done (Upgrade to version 44 done, 10 min after the error), the DB started to be filled with the missing data. I have no idea how this actually works, but I assume the states were stored on my hard drive temporarily, and I assume this was handled by MariaDB. See attached image for my disk usage.

image

Everything seems to be working, the migration seems to have succeeded. Upgraded to the other betas and now the release version, and I haven't seen any recorder related warnings/errors.

From searching a bit on how locks works, this could be as simple as my DB was way too big and I ran out of some kind of cache with the default config. If so, this is an edge case and I assume this won't happen to most people, and we can close this ticket.

js94x commented 2 months ago
Sep 15 12:30:02 utility-02 hass[1201102]: 2024-09-15 12:30:02.544 WARNING (Recorder) [homeassistant.components.recorder.migration] The database is about to upgrade from schema version 46 to 47
Sep 15 12:30:02 utility-02 hass[1201102]: 2024-09-15 12:30:02.621 WARNING (Recorder) [homeassistant.components.recorder.migration] Adding foreign key constraint to states.attributes_id. Note: this can take several minutes on large databases and slow machines. Please be patient!
Sep 15 12:48:14 utility-02 hass[1201102]: 2024-09-15 12:48:14.566 ERROR (Recorder) [homeassistant.helpers.recorder] Error executing query
Sep 15 12:48:14 utility-02 hass[1201102]:   File "/home/hass/homeassistant/lib/python3.12/site-packages/homeassistant/helpers/recorder.py", line 101, in session_scope
Sep 15 12:48:14 utility-02 hass[1201102]:   File "/home/hass/homeassistant/lib/python3.12/site-packages/homeassistant/components/recorder/migration.py", line 753, in _add_constraint
Sep 15 12:48:14 utility-02 hass[1201102]: 2024-09-15 12:48:14.669 ERROR (Recorder) [homeassistant.components.recorder.migration] Could not update foreign options in states table, will delete violations and try again

I also had some problems with the indexes and foreign key constraints while database schema migration.

For me it helped to disable foreign_key_checks in my MariaDB temporarily. Go to MariaDB (or mysql) cli and enter set global foreign_key_checks=0;. Then restart HA. It will now run through the migrations. Afterwards revert the setting to its initial value by enterin set global foreign_key_checks=1;.

andbad commented 2 months ago
Sep 15 12:30:02 utility-02 hass[1201102]: 2024-09-15 12:30:02.544 WARNING (Recorder) [homeassistant.components.recorder.migration] The database is about to upgrade from schema version 46 to 47
Sep 15 12:30:02 utility-02 hass[1201102]: 2024-09-15 12:30:02.621 WARNING (Recorder) [homeassistant.components.recorder.migration] Adding foreign key constraint to states.attributes_id. Note: this can take several minutes on large databases and slow machines. Please be patient!
Sep 15 12:48:14 utility-02 hass[1201102]: 2024-09-15 12:48:14.566 ERROR (Recorder) [homeassistant.helpers.recorder] Error executing query
Sep 15 12:48:14 utility-02 hass[1201102]:   File "/home/hass/homeassistant/lib/python3.12/site-packages/homeassistant/helpers/recorder.py", line 101, in session_scope
Sep 15 12:48:14 utility-02 hass[1201102]:   File "/home/hass/homeassistant/lib/python3.12/site-packages/homeassistant/components/recorder/migration.py", line 753, in _add_constraint
Sep 15 12:48:14 utility-02 hass[1201102]: 2024-09-15 12:48:14.669 ERROR (Recorder) [homeassistant.components.recorder.migration] Could not update foreign options in states table, will delete violations and try again

I also had some problems with the indexes and foreign key constraints while database schema migration.

For me it helped to disable foreign_key_checks in my MariaDB temporarily. Go to MariaDB (or mysql) cli and enter set global foreign_key_checks=0;. Then restart HA. It will now run through the migrations. Afterwards revert the setting to its initial value by enterin set global foreign_key_checks=1;.

I had the following error:

2024-09-16 10:36:39.498 ERROR (Recorder) [homeassistant.components.recorder.migration] Could not update foreign options in states table
Traceback (most recent call last):
  File ".homeassistant/homeassistant/lib/python3.12/site-packages/sqlalchemy/engine/base.py", line 1967, in _exec_single_context
    self.dialect.do_execute(
  File ".homeassistant/homeassistant/lib/python3.12/site-packages/sqlalchemy/engine/default.py", line 924, in do_execute
    cursor.execute(statement, parameters)
  File ".homeassistant/homeassistant/lib/python3.12/site-packages/pymysql/cursors.py", line 153, in execute
    result = self._query(query)
             ^^^^^^^^^^^^^^^^^^
  File ".homeassistant/homeassistant/lib/python3.12/site-packages/pymysql/cursors.py", line 322, in _query
    conn.query(q)
  File ".homeassistant/homeassistant/lib/python3.12/site-packages/pymysql/connections.py", line 558, in query
    self._affected_rows = self._read_query_result(unbuffered=unbuffered)
                          ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File ".homeassistant/homeassistant/lib/python3.12/site-packages/pymysql/connections.py", line 822, in _read_query_result
    result.read()
  File ".homeassistant/homeassistant/lib/python3.12/site-packages/pymysql/connections.py", line 1200, in read
    first_packet = self.connection._read_packet()
                   ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File ".homeassistant/homeassistant/lib/python3.12/site-packages/pymysql/connections.py", line 772, in _read_packet
    packet.raise_for_error()
  File ".homeassistant/homeassistant/lib/python3.12/site-packages/pymysql/protocol.py", line 221, in raise_for_error
    err.raise_mysql_exception(self._data)
  File ".homeassistant/homeassistant/lib/python3.12/site-packages/pymysql/err.py", line 143, in raise_mysql_exception
    raise errorclass(errno, errval)
pymysql.err.OperationalError: (1034, "Index for table 'homeassistant/#sql-alter-1-126' is corrupt; try to repair it")

The above exception was the direct cause of the following exception:
Traceback (most recent call last):
  File ".homeassistant/homeassistant/lib/python3.12/site-packages/homeassistant/components/recorder/migration.py", line 753, in _add_constraint
    connection.execute(add_constraint)
  File ".homeassistant/homeassistant/lib/python3.12/site-packages/sqlalchemy/engine/base.py", line 1418, in execute
    return meth(
           ^^^^^
  File ".homeassistant/homeassistant/lib/python3.12/site-packages/sqlalchemy/sql/ddl.py", line 180, in _execute_on_connection
    return connection._execute_ddl(
           ^^^^^^^^^^^^^^^^^^^^^^^^
  File ".homeassistant/homeassistant/lib/python3.12/site-packages/sqlalchemy/engine/base.py", line 1529, in _execute_ddl
    ret = self._execute_context(
          ^^^^^^^^^^^^^^^^^^^^^^
  File ".homeassistant/homeassistant/lib/python3.12/site-packages/sqlalchemy/engine/base.py", line 1846, in _execute_context
    return self._exec_single_context(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File ".homeassistant/homeassistant/lib/python3.12/site-packages/sqlalchemy/engine/base.py", line 1986, in _exec_single_context
    self._handle_dbapi_exception(
  File ".homeassistant/homeassistant/lib/python3.12/site-packages/sqlalchemy/engine/base.py", line 2353, in _handle_dbapi_exception
    raise sqlalchemy_exception.with_traceback(exc_info[2]) from e
  File ".homeassistant/homeassistant/lib/python3.12/site-packages/sqlalchemy/engine/base.py", line 1967, in _exec_single_context
    self.dialect.do_execute(
  File ".homeassistant/homeassistant/lib/python3.12/site-packages/sqlalchemy/engine/default.py", line 924, in do_execute
    cursor.execute(statement, parameters)
  File ".homeassistant/homeassistant/lib/python3.12/site-packages/pymysql/cursors.py", line 153, in execute
    result = self._query(query)
             ^^^^^^^^^^^^^^^^^^
  File ".homeassistant/homeassistant/lib/python3.12/site-packages/pymysql/cursors.py", line 322, in _query
    conn.query(q)
  File ".homeassistant/homeassistant/lib/python3.12/site-packages/pymysql/connections.py", line 558, in query
    self._affected_rows = self._read_query_result(unbuffered=unbuffered)
                          ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File ".homeassistant/homeassistant/lib/python3.12/site-packages/pymysql/connections.py", line 822, in _read_query_result
    result.read()
  File ".homeassistant/homeassistant/lib/python3.12/site-packages/pymysql/connections.py", line 1200, in read
    first_packet = self.connection._read_packet()
  File ".homeassistant/homeassistant/lib/python3.12/site-packages/pymysql/connections.py", line 772, in _read_packet
    packet.raise_for_error()
  File ".homeassistant/homeassistant/lib/python3.12/site-packages/pymysql/protocol.py", line 221, in raise_for_error
    err.raise_mysql_exception(self._data)
  File ".homeassistant/homeassistant/lib/python3.12/site-packages/pymysql/err.py", line 143, in raise_mysql_exception
    raise errorclass(errno, errval)
sqlalchemy.exc.OperationalError: (pymysql.err.OperationalError) (1034, "Index for table 'homeassistant/#sql-alter-1-126' is corrupt; try to repair it")
[SQL: ALTER TABLE states ADD FOREIGN KEY(old_state_id) REFERENCES states (state_id)]
(Background on this error at: https://sqlalche.me/e/20/e3q8)

I solved with your hint. Thanks

By(t)e