| Bug #113430 | Query slowness in Delete query with many child table | ||
|---|---|---|---|
| Submitted: | 14 Dec 2023 23:06 | Modified: | 22 Dec 2023 14:00 |
| Reporter: | TAMILMARAN C | Email Updates: | |
| Status: | Not a Bug | Impact on me: | |
| Category: | MySQL Server | Severity: | S3 (Non-critical) |
| Version: | 8.0.34 | OS: | Any |
| Assigned to: | CPU Architecture: | Any | |
[15 Dec 2023 13:33]
MySQL Verification Team
Hi MR. C, Thank you very much for your bug report. However, we do not see what is a bug that you are reporting. Deleting from the parent table that has 10.000 child tables in 3 seconds is very fast, indeed. You claim that 5.7 is much faster ....... What are the times there ????
[17 Dec 2023 14:02]
TAMILMARAN C
In 5.7 took 1ms alone. mysql> delete from parent_table_2 where id =1; Query OK, 0 rows affected (0.01 sec) mysql> explain delete from parent_table_2 where id =1; +----+-------------+----------------+------------+-------+---------------+---------+---------+-------+------+----------+-------------+ | id | select_type | table | partitions | type | possible_keys | key | key_len | ref | rows | filtered | Extra | +----+-------------+----------------+------------+-------+---------------+---------+---------+-------+------+----------+-------------+ | 1 | DELETE | parent_table_2 | NULL | range | PRIMARY | PRIMARY | 4 | const | 1 | 100.00 | Using where | +----+-------------+----------------+------------+-------+---------------+---------+---------+-------+------+----------+-------------+ 1 row in set (0.00 sec) By the way there is no rows in parent_table_2. That is an empty table. In Mysql 8, even explain query itself taking more time. mysql> delete from parent_table_2 where id =1; Query OK, 0 rows affected (3.18 sec) mysql> explain delete from parent_table_2 where id =1; +----+-------------+----------------+------------+-------+---------------+---------+---------+-------+------+----------+-------------+ | id | select_type | table | partitions | type | possible_keys | key | key_len | ref | rows | filtered | Extra | +----+-------------+----------------+------------+-------+---------------+---------+---------+-------+------+----------+-------------+ | 1 | DELETE | parent_table_2 | NULL | range | PRIMARY | PRIMARY | 4 | const | 1 | 100.00 | Using where | +----+-------------+----------------+------------+-------+---------------+---------+---------+-------+------+----------+-------------+ 1 row in set, 1 warning (3.90 sec)
[18 Dec 2023 11:32]
MySQL Verification Team
Hi Mr. C, That is expected behaviour, since 8.0 has many additional checks added, since it has so many more features. Can you reproduce the same slowness with 10 or 100 child tables ?????
[22 Dec 2023 14:00]
TAMILMARAN C
We increased table_definition_cache to 10K, After that we didn't face the issue. Still we ran perf and took flamegraph for the query in mysql and went through slow processing functions. 1. sql_base.open_and_process_routine When CUD query is fired to Parent, MySQL requires SW lock for all its child. In this work item - https://dev.MySQL.com/worklog/task/?id=6049, MySQL team has mentioned they are not intended to open all the child tables. Just needed to acquire SW lock for the child. But when we checked the code, all the child table is opened and its respective info is stored in def cache(table share). 2. sql_base.get_table_share Also, in our test case, a parent table with 4K child table explain delete query took 21sec. In this get_table_share alone took 20.84sec. And inside this get_table_share, read histogram contributes around 10-11sec(50%), we haven’t created any histogram but still 8.0 tries to load histogram statistics in table_share. So when we commented this read_histogram method we were able to gain 50% faster execution speed. Is there any possible ways to fix/handle this in better way?
[22 Dec 2023 14:00]
TAMILMARAN C
Flamegraph
Attachment: Screenshot 2023-12-21 at 10.55.40 PM.png (image/png, text), 852.82 KiB.
[8 Jan 2024 10:23]
MySQL Verification Team
Hi Mr. C, Thank you for the information provided. You wrote that when you increased table_definition_cache to 10K, the slowness disappeared. That means that your report is not a bug , but it was just a misconfiguration. Next, regarding locking the table, you can not lock a table unless it is open. Last, regarding histograms, there are so many installations with many tables using histograms, so we can not just comment out that part of the code. Checking for histograms will take the same time as attempting to load them. If there were histograms, that part of the code would have taken significantly longer time. Histograms are a new feature and they can not be just removed.
Description: Facing slowness in Delete query for a table which has many child tables. Even the explain query for that delete query itself slow. mysql> delete from parent_table_2 where id =1; Query OK, 0 rows affected (4.45 sec) mysql> explain delete from parent_table_2 where id =1; +----+-------------+----------------+------------+-------+---------------+---------+---------+-------+------+----------+-------------+ | id | select_type | table | partitions | type | possible_keys | key | key_len | ref | rows | filtered | Extra | +----+-------------+----------------+------------+-------+---------------+---------+---------+-------+------+----------+-------------+ | 1 | DELETE | parent_table_2 | NULL | range | PRIMARY | PRIMARY | 4 | const | 1 | 100.00 | Using where | +----+-------------+----------------+------------+-------+---------------+---------+---------+-------+------+----------+-------------+ 1 row in set, 1 warning (3.28 sec) It is consistently reproducing. Same can't be reproducible in Mysql 5.7.30. How to repeat: Creating a parent with 10000 direct child table with FK ON DELETE CONSTRAINT. CREATE TABLE parent_table_2 ( id INT PRIMARY KEY, name VARCHAR(255) ); Using a shell script created 10k child tables for that table. #!/bin/bash MYSQL_USER="your_username" MYSQL_PASSWORD="your_password" MYSQL_DATABASE="your_database" for ((i=1; i<=10000; i++)); do TABLE_NAME="table_child_FK_WITH_ON_DELETE_$i" QUERY="CREATE TABLE IF NOT EXISTS $TABLE_NAME ( id INT PRIMARY KEY, column1 INT, column2 VARCHAR(255), FOREIGN KEY (column1) REFERENCES parent_table_2(id) ON DELETE CASCADE );" mysql -u "$MYSQL_USER" -p"$MYSQL_PASSWORD" "$MYSQL_DATABASE" -e "$QUERY" done parent_table_2 has no data at all. Even though delete query fired to this table is facing slowness. mysql> delete from parent_table_2 where id =1; Query OK, 0 rows affected (4.45 sec) +--------------------------------+----------+ | Status | Duration | +--------------------------------+----------+ | starting | 0.000119 | | Executing hook on transaction | 0.000010 | | starting | 0.000010 | | checking permissions | 0.000007 | | Opening tables | 1.876346 | | init | 0.000048 | | System lock | 0.000092 | | updating | 0.000035 | | end | 0.000005 | | query end | 0.000004 | | waiting for handler commit | 0.000065 | | Waiting for semi-sync ACK from | 0.000511 | | waiting for handler commit | 0.000015 | | closing tables | 2.571113 | | freeing items | 0.000098 | | logging slow query | 0.000056 | | cleaning up | 0.001471 | +--------------------------------+----------+ Query is taking time in Opening tables and closing tables. From mysql documentation Opening tables The thread is trying to open a table. This is should be a very fast procedure, unless something prevents opening. For example, an ALTER TABLE or a LOCK TABLE statement can prevent opening a table until the statement is finished. It is also worth checking that your table_open_cache value is large enough. closing tables The thread is flushing the changed table data to disk and closing the used tables. This should be a fast operation. If not, verify that you do not have a full disk and that the disk is not in very heavy use. Checked both: table_open_cache is 524288 and Disk usage usage very minimal. When tried explain query for that delete, it is also slow. mysql> explain delete from parent_table_2 where id =1; +----+-------------+----------------+------------+-------+---------------+---------+---------+-------+------+----------+-------------+ | id | select_type | table | partitions | type | possible_keys | key | key_len | ref | rows | filtered | Extra | +----+-------------+----------------+------------+-------+---------------+---------+---------+-------+------+----------+-------------+ | 1 | DELETE | parent_table_2 | NULL | range | PRIMARY | PRIMARY | 4 | const | 1 | 100.00 | Using where | +----+-------------+----------------+------------+-------+---------------+---------+---------+-------+------+----------+-------------+ 1 row in set, 1 warning (2.77 sec) +--------------------------------+----------+ | Status | Duration | +--------------------------------+----------+ | starting | 0.000123 | | Executing hook on transaction | 0.000020 | | starting | 0.000016 | | checking permissions | 0.000010 | | Opening tables | 1.616061 | | init | 0.000047 | | System lock | 0.000057 | | end | 0.000005 | | query end | 0.000004 | | waiting for handler commit | 0.000007 | | closing tables | 1.160547 | | freeing items | 0.000085 | | cleaning up | 0.000666 | +--------------------------------+----------+ When checked other mysql show status parameters, i can find increase in Opened_table_definitions. mysql> show status like "table_open_cache%"; show status like "open_table%"; show status like "opened_table%"; +----------------------------+-------+ | Variable_name | Value | +----------------------------+-------+ | Table_open_cache_hits | 0 | | Table_open_cache_misses | 0 | | Table_open_cache_overflows | 0 | +----------------------------+-------+ 3 rows in set (0.01 sec) +------------------------+--------+ | Variable_name | Value | +------------------------+--------+ | Open_table_definitions | 15659 | | Open_tables | 128380 | +------------------------+--------+ 2 rows in set (0.00 sec) +--------------------------+-------+ | Variable_name | Value | +--------------------------+-------+ | Opened_table_definitions | 0 | | Opened_tables | 0 | +--------------------------+-------+ 2 rows in set (0.00 sec) mysql> explain delete from parent_table_2 where id =1; +----+-------------+----------------+------------+-------+---------------+---------+---------+-------+------+----------+-------------+ | id | select_type | table | partitions | type | possible_keys | key | key_len | ref | rows | filtered | Extra | +----+-------------+----------------+------------+-------+---------------+---------+---------+-------+------+----------+-------------+ | 1 | DELETE | parent_table_2 | NULL | range | PRIMARY | PRIMARY | 4 | const | 1 | 100.00 | Using where | +----+-------------+----------------+------------+-------+---------------+---------+---------+-------+------+----------+-------------+ 1 row in set, 1 warning (3.28 sec) mysql> show status like "table_open_cache%"; show status like "open_table%"; show status like "opened_table%"; +----------------------------+--------+ | Variable_name | Value | +----------------------------+--------+ | Table_open_cache_hits | 179997 | | Table_open_cache_misses | 1 | | Table_open_cache_overflows | 0 | +----------------------------+--------+ 3 rows in set (0.00 sec) +------------------------+--------+ | Variable_name | Value | +------------------------+--------+ | Open_table_definitions | 15659 | | Open_tables | 128381 | +------------------------+--------+ 2 rows in set (0.00 sec) +--------------------------+-------+ | Variable_name | Value | +--------------------------+-------+ | Opened_table_definitions | 9999 | | Opened_tables | 1 | +--------------------------+-------+ 2 rows in set (0.00 sec) In Mysql 5.7.30 this issue is not occurring and also there is no increase in Opened_table_definitions.