core: HA 2022.4 database migration stuck with MariaDB

The problem

Updating from 2022.3.7 to 2022.4.0, the database migration never finished. CPU and IO utilization was 0. I checked the running MariaDB processes and saw this:

MariaDB [home_assistant]> show processlist;
+-----+------+-----------------+----------------+---------+------+---------------------------------+--------------------------------------------------+----------+
| Id  | User | Host            | db             | Command | Time | State                           | Info                                             | Progress |
+-----+------+-----------------+----------------+---------+------+---------------------------------+--------------------------------------------------+----------+
|  99 | hass | localhost:50986 | home_assistant | Sleep   |  181 |                                 | NULL                                             |    0.000 |
| 100 | hass | localhost:51128 | home_assistant | Sleep   |    7 |                                 | NULL                                             |    0.000 |
| 102 | hass | localhost:51282 | home_assistant | Query   |  180 | Waiting for table metadata lock | ALTER TABLE states ADD attributes_id INTEGER(20) |    0.000 |
| 107 | hass | localhost       | home_assistant | Query   |    0 | Init                            | show processlist                                 |    0.000 |
+-----+------+-----------------+----------------+---------+------+---------------------------------+--------------------------------------------------+----------+
4 rows in set (0.000 sec)

After some googling, I found various queries to run against the INFORMATION_SCHEMA for finding out what was taking the lock, but there wasn’t anything. I stopped HA and started it again, and then it got stuck on another query:

+----+------+-----------------+----------------+---------+------+---------------------------------+----------------------------------------------------------------+----------+
| Id | User | Host            | db             | Command | Time | State                           | Info                                                           | Progress |
+----+------+-----------------+----------------+---------+------+---------------------------------+----------------------------------------------------------------+----------+
| 36 | hass | localhost       | home_assistant | Query   |    0 | Init                            | show processlist                                               |    0.000 |
| 37 | hass | localhost:53270 | home_assistant | Sleep   |  114 |                                 | NULL                                                           |    0.000 |
| 38 | hass | localhost:53330 | home_assistant | Sleep   |   32 |                                 | NULL                                                           |    0.000 |
| 39 | hass | localhost:53500 | home_assistant | Sleep   |  114 |                                 | NULL                                                           |    0.000 |
| 40 | hass | localhost:53502 | home_assistant | Query   |  114 | Waiting for table metadata lock | CREATE INDEX ix_states_attributes_id ON states (attributes_id) |    0.000 |
+----+------+-----------------+----------------+---------+------+---------------------------------+----------------------------------------------------------------+----------+
5 rows in set (0.000 sec)

And I verified that the new column from the previous query had actually been created:

MariaDB [home_assistant]> show create table states;
+--------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| Table  | Create Table                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                     |
+--------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| states | CREATE TABLE `states` (
  `state_id` int(11) NOT NULL AUTO_INCREMENT,
  `domain` varchar(64) COLLATE utf8mb4_unicode_ci DEFAULT NULL,
  `entity_id` varchar(255) COLLATE utf8mb4_unicode_ci DEFAULT NULL,
  `state` varchar(255) COLLATE utf8mb4_unicode_ci DEFAULT NULL,
  `attributes` longtext COLLATE utf8mb4_unicode_ci DEFAULT NULL,
  `event_id` int(11) DEFAULT NULL,
  `last_changed` datetime(6) DEFAULT NULL,
  `last_updated` datetime(6) DEFAULT NULL,
  `created` datetime(6) DEFAULT NULL,
  `old_state_id` int(11) DEFAULT NULL,
  `attributes_id` int(20) DEFAULT NULL,
  PRIMARY KEY (`state_id`),
  KEY `ix_states_old_state_id` (`old_state_id`),
  KEY `ix_states_last_updated` (`last_updated`),
  KEY `ix_states_event_id` (`event_id`),
  KEY `ix_states_entity_id_last_updated` (`entity_id`,`last_updated`),
  CONSTRAINT `states_ibfk_1` FOREIGN KEY (`event_id`) REFERENCES `events` (`event_id`) ON DELETE CASCADE,
  CONSTRAINT `states_ibfk_2` FOREIGN KEY (`old_state_id`) REFERENCES `states` (`state_id`)
) ENGINE=InnoDB AUTO_INCREMENT=41396921 DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_unicode_ci |
+--------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
1 row in set (0.001 sec)

I stopped HA again, and kept running SHOW PROCESSLIST, and immediately after HA had stopped, the Waiting on metadata lock disappeared and the index was actually being created:

MariaDB [home_assistant]> show processlist;
+----+------+-----------------+----------------+---------+------+----------------+----------------------------------------------------------------+----------+
| Id | User | Host            | db             | Command | Time | State          | Info                                                           | Progress |
+----+------+-----------------+----------------+---------+------+----------------+----------------------------------------------------------------+----------+
| 36 | hass | localhost       | home_assistant | Query   |    0 | Init           | show processlist                                               |    0.000 |
| 40 | hass | localhost:53502 | home_assistant | Query   |  119 | Altering table | CREATE INDEX ix_states_attributes_id ON states (attributes_id) |    0.000 |
+----+------+-----------------+----------------+---------+------+----------------+----------------------------------------------------------------+----------+
2 rows in set (0.000 sec)

After the second stop, this was in the log:

2022-04-07 21:22:02 WARNING (Recorder) [homeassistant.components.recorder.migration] Database is about to upgrade. Schema version: 24
2022-04-07 21:22:02 WARNING (Recorder) [homeassistant.components.recorder.migration] Adding columns attributes_id to table states. Note: this can take several minutes on large databases and slow computers. Please be patient!
2022-04-07 21:22:02 WARNING (Recorder) [homeassistant.components.recorder.migration] Column attributes_id already exists on states, continuing
2022-04-07 21:22:02 WARNING (Recorder) [homeassistant.components.recorder.migration] Adding index `ix_states_attributes_id` to database. Note: this can take several minutes on large databases and slow computers. Please be patient!

I started HA again, and at that point, it seems like the migration went through (no more queries stuck in MariaDB at least):

2022-04-07 21:24:55 WARNING (Recorder) [homeassistant.components.recorder.migration] Database is about to upgrade. Schema version: 24
2022-04-07 21:24:55 WARNING (Recorder) [homeassistant.components.recorder.migration] Adding columns attributes_id to table states. Note: this can take several minutes on large databases and slow compute
rs. Please be patient!
2022-04-07 21:24:56 WARNING (Recorder) [homeassistant.components.recorder.migration] Column attributes_id already exists on states, continuing
2022-04-07 21:24:56 WARNING (Recorder) [homeassistant.components.recorder.migration] Adding index `ix_states_attributes_id` to database. Note: this can take several minutes on large databases and slow c
omputers. Please be patient!
2022-04-07 21:24:56 WARNING (Recorder) [homeassistant.components.recorder.migration] Index ix_states_attributes_id already exists on states, continuing

Also reported by another user on Discord: https://discord.com/channels/330944238910963714/332167321311510530/961616149475385455

$ cat /etc/os-release
PRETTY_NAME="Raspbian GNU/Linux 10 (buster)"
NAME="Raspbian GNU/Linux"
VERSION_ID="10"
VERSION="10 (buster)"
VERSION_CODENAME=buster
ID=raspbian
ID_LIKE=debian
HOME_URL="http://www.raspbian.org/"
SUPPORT_URL="http://www.raspbian.org/RaspbianForums"
BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs"

$ mysql -V
mysql  Ver 15.1 Distrib 10.3.34-MariaDB, for debian-linux-gnueabihf (armv8l) using readline 5.2

What version of Home Assistant Core has the issue?

core-2022.4.0

What was the last working version of Home Assistant Core?

core-2022.3.7

What type of installation are you running?

Home Assistant Container

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

recorder:
  db_url: !secret mariadb_url
  purge_keep_days: 30
  exclude:
    entities:
      - sensor.date_time
      - sensor.time

mariadb_url: mysql://hass:xxxx@127.0.0.1/home_assistant?charset=utf8mb4

Anything in the logs that might be useful for us?

2022-04-07 21:10:54 WARNING (Recorder) [homeassistant.components.recorder.migration] Database is about to upgrade. Schema version: 24
2022-04-07 21:10:54 WARNING (Recorder) [homeassistant.components.recorder.migration] Adding columns attributes_id to table states. Note: this can take several minutes on large databases and slow computers. Please be patient!

Additional information

No response