core: Database migration failed to create index when updating from 2021.12 to 2022.2

The problem

Database migration failed. Log is attached.

What version of Home Assistant Core has the issue?

2022.2

What was the last working version of Home Assistant Core?

2021.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/

Example YAML snippet

recorder:
  db_url: mysql://username:password@IP/homeassistant?charset=utf8
  purge_keep_days: 365
  exclude:
    domains:
      - automation
      - updater

Anything in the logs that might be useful for us?

2022-02-03 00:05:09 WARNING (Recorder) [homeassistant.components.recorder.statistics] Found more than 999999 duplicated statistic rows, please report at https://github.com/home-assistant/core/issues?q=is%3Aissue+label%3A"integration%3A+recorder"+
2022-02-03 00:05:16 WARNING (Recorder) [homeassistant.components.recorder.migration] Adding index `ix_statistics_statistic_id_start` to database. Note: this can take several minutes on large databases and slow computers. Please be patient!
2022-02-03 00:05:17 ERROR (Recorder) [homeassistant.components.recorder.util] Error executing query: (MySQLdb._exceptions.IntegrityError) (1062, "Duplicate entry '7-2021-11-07 05:00:00.000000' for key 'ix_statistics_statistic_id_start'")
[SQL: CREATE UNIQUE INDEX ix_statistics_statistic_id_start ON statistics (metadata_id, start)]
(Background on this error at: https://sqlalche.me/e/14/gkpj)
2022-02-03 00:05:17 ERROR (Recorder) [homeassistant.components.recorder] Database error during schema migration
Traceback (most recent call last):
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1802, in _execute_context
    self.dialect.do_execute(
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/engine/default.py", line 719, in do_execute
    cursor.execute(statement, parameters)
  File "/usr/local/lib/python3.9/site-packages/MySQLdb/cursors.py", line 206, in execute
    res = self._query(query)
  File "/usr/local/lib/python3.9/site-packages/MySQLdb/cursors.py", line 319, in _query
    db.query(q)
  File "/usr/local/lib/python3.9/site-packages/MySQLdb/connections.py", line 259, in query
    _mysql.connection.query(self, query)
MySQLdb._exceptions.IntegrityError: (1062, "Duplicate entry '7-2021-11-07 05:00:00.000000' for key 'ix_statistics_statistic_id_start'")

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

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/recorder/__init__.py", line 852, in _migrate_schema_and_setup_run
    migration.migrate_schema(self, current_version)
  File "/usr/src/homeassistant/homeassistant/components/recorder/migration.py", line 78, in migrate_schema
    _apply_update(instance, session, new_version, current_version)
  File "/usr/src/homeassistant/homeassistant/components/recorder/migration.py", line 595, in _apply_update
    _create_index(connection, "statistics", "ix_statistics_statistic_id_start")
  File "/usr/src/homeassistant/homeassistant/components/recorder/migration.py", line 106, in _create_index
    index.create(connection)
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/sql/schema.py", line 4208, in create
    bind._run_ddl_visitor(ddl.SchemaGenerator, self, checkfirst=checkfirst)
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 2113, in _run_ddl_visitor
    visitorcallable(self.dialect, self, **kwargs).traverse_single(element)
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/sql/visitors.py", line 524, in traverse_single
    return meth(obj, **kw)
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/sql/ddl.py", line 933, in visit_index
    self.connection.execute(CreateIndex(index))
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1289, in execute
    return meth(self, multiparams, params, _EMPTY_EXECUTION_OPTS)
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/sql/ddl.py", line 77, in _execute_on_connection
    return connection._execute_ddl(
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1381, in _execute_ddl
    ret = self._execute_context(
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1845, in _execute_context
    self._handle_dbapi_exception(
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 2026, in _handle_dbapi_exception
    util.raise_(
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/util/compat.py", line 207, in raise_
    raise exception
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1802, in _execute_context
    self.dialect.do_execute(
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/engine/default.py", line 719, in do_execute
    cursor.execute(statement, parameters)
  File "/usr/local/lib/python3.9/site-packages/MySQLdb/cursors.py", line 206, in execute
    res = self._query(query)
  File "/usr/local/lib/python3.9/site-packages/MySQLdb/cursors.py", line 319, in _query
    db.query(q)
  File "/usr/local/lib/python3.9/site-packages/MySQLdb/connections.py", line 259, in query
    _mysql.connection.query(self, query)
sqlalchemy.exc.IntegrityError: (MySQLdb._exceptions.IntegrityError) (1062, "Duplicate entry '7-2021-11-07 05:00:00.000000' for key 'ix_statistics_statistic_id_start'")
[SQL: CREATE UNIQUE INDEX ix_statistics_statistic_id_start ON statistics (metadata_id, start)]
(Background on this error at: https://sqlalche.me/e/14/gkpj)
2022-02-03 00:08:59 ERROR (MainThread) [aiohttp.server] Error handling request
Traceback (most recent call last):
  File "/usr/local/lib/python3.9/site-packages/aiohttp/web_protocol.py", line 435, in _handle_request
    resp = await request_handler(request)
  File "/usr/local/lib/python3.9/site-packages/aiohttp/web_app.py", line 473, in _handle
    match_info = await self._router.resolve(request)
  File "/usr/local/lib/python3.9/site-packages/aiohttp/web_urldispatcher.py", line 1010, in resolve
    match_dict, allowed = await resource.resolve(request)
  File "/usr/src/homeassistant/homeassistant/components/frontend/__init__.py", line 536, in resolve
    and request.url.parts[1] not in self.hass.data[DATA_PANELS]
IndexError: tuple index out of range
2022-02-03 00:17:14 ERROR (MainThread) [aiohttp.server] Error handling request
Traceback (most recent call last):
  File "/usr/local/lib/python3.9/site-packages/aiohttp/web_protocol.py", line 435, in _handle_request
    resp = await request_handler(request)
  File "/usr/local/lib/python3.9/site-packages/aiohttp/web_app.py", line 504, in _handle
    resp = await handler(request)
  File "/usr/local/lib/python3.9/site-packages/aiohttp/web_middlewares.py", line 117, in impl
    return await handler(request)
  File "/usr/src/homeassistant/homeassistant/components/http/security_filter.py", line 60, in security_filter_middleware
    return await handler(request)
  File "/usr/src/homeassistant/homeassistant/components/http/forwarded.py", line 220, in forwarded_middleware
    return await handler(request)
  File "/usr/src/homeassistant/homeassistant/components/http/request_context.py", line 28, in request_context_middleware
    return await handler(request)
  File "/usr/src/homeassistant/homeassistant/components/http/ban.py", line 79, in ban_middleware
    return await handler(request)
  File "/usr/src/homeassistant/homeassistant/components/http/auth.py", line 219, in auth_middleware
    return await handler(request)
  File "/usr/src/homeassistant/homeassistant/components/http/view.py", line 137, in handle
    result = await result
  File "/usr/src/homeassistant/homeassistant/components/logbook/__init__.py", line 257, in get
    return await hass.async_add_executor_job(json_events)
  File "/usr/local/lib/python3.9/concurrent/futures/thread.py", line 52, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/src/homeassistant/homeassistant/components/logbook/__init__.py", line 245, in json_events
    _get_events(
  File "/usr/src/homeassistant/homeassistant/components/logbook/__init__.py", line 446, in _get_events
    with session_scope(hass=hass) as session:
  File "/usr/local/lib/python3.9/contextlib.py", line 119, in __enter__
    return next(self.gen)
  File "/usr/src/homeassistant/homeassistant/components/recorder/util.py", line 76, in session_scope
    session = hass.data[DATA_INSTANCE].get_session()
TypeError: 'NoneType' object is not callable
2022-02-03 00:17:20 ERROR (MainThread) [aiohttp.server] Error handling request
Traceback (most recent call last):
  File "/usr/local/lib/python3.9/site-packages/aiohttp/web_protocol.py", line 435, in _handle_request
    resp = await request_handler(request)
  File "/usr/local/lib/python3.9/site-packages/aiohttp/web_app.py", line 504, in _handle
    resp = await handler(request)
  File "/usr/local/lib/python3.9/site-packages/aiohttp/web_middlewares.py", line 117, in impl
    return await handler(request)
  File "/usr/src/homeassistant/homeassistant/components/http/security_filter.py", line 60, in security_filter_middleware
    return await handler(request)
  File "/usr/src/homeassistant/homeassistant/components/http/forwarded.py", line 220, in forwarded_middleware
    return await handler(request)
  File "/usr/src/homeassistant/homeassistant/components/http/request_context.py", line 28, in request_context_middleware
    return await handler(request)
  File "/usr/src/homeassistant/homeassistant/components/http/ban.py", line 79, in ban_middleware
    return await handler(request)
  File "/usr/src/homeassistant/homeassistant/components/http/auth.py", line 219, in auth_middleware
    return await handler(request)
  File "/usr/src/homeassistant/homeassistant/components/http/view.py", line 137, in handle
    result = await result
  File "/usr/src/homeassistant/homeassistant/components/history/__init__.py", line 235, in get
    await hass.async_add_executor_job(
  File "/usr/local/lib/python3.9/concurrent/futures/thread.py", line 52, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/src/homeassistant/homeassistant/components/history/__init__.py", line 260, in _sorted_significant_states_json
    with session_scope(hass=hass) as session:
  File "/usr/local/lib/python3.9/contextlib.py", line 119, in __enter__
    return next(self.gen)
  File "/usr/src/homeassistant/homeassistant/components/recorder/util.py", line 76, in session_scope
    session = hass.data[DATA_INSTANCE].get_session()
TypeError: 'NoneType' object is not callable

Additional information

MariaDB version: mysql Ver 15.1 Distrib 10.3.31-MariaDB, for debian-linux-gnu (x86_64) using readline 5.2

No response

About this issue

  • Original URL
  • State: closed
  • Created 2 years ago
  • Reactions: 1
  • Comments: 30 (7 by maintainers)

Most upvoted comments

The issue reported by @xuan-w is fixed by #65641 which will be included in HA Core 2022.2.2

@antbarney your problem is different, it’s related to not correctly identifying PostgreSQL indices combined with not handling errors correctly during migration. Could you create a new issue for that please? A partial correction is here: #65672, it makes sure migration can continue

So the error handling should be the only real issue, as I explained in our Discord chat I recently migrated from MariaDB to PostgreSQL and used pgloader to migrate my data, it appears that it changes the names of the indcies when it does this so they where not as expected. After correcting those my migration finished successfully, so this is looking like user error more then anything >,<

Thanks for all the hard work you guys put into Home Assistant!

Hi

Problem with low disk space is also described here #65574