| Bug #101900 | Add partition is slow | ||
|---|---|---|---|
| Submitted: | 8 Dec 2020 3:21 | Modified: | 8 Dec 2020 17:21 |
| Reporter: | peng gao | Email Updates: | |
| Status: | Verified | Impact on me: | |
| Category: | MySQL Server: InnoDB storage engine | Severity: | S2 (Serious) |
| Version: | 8.0.21 | OS: | Linux (7.6) |
| Assigned to: | CPU Architecture: | Any | |
[8 Dec 2020 3:35]
peng gao
In test environment I add a sleep in btr_drop_ahi_for_table. But in our product environment this add partition operation expand 120 seconds.
[8 Dec 2020 6:27]
peng gao
In 8.0.19 also have this problem
[8 Dec 2020 16:22]
MySQL Verification Team
Hi,
I'm having issues reproducing this on 8.0.22
mysql [localhost:8022] {msandbox} (test) > select count(*) from sales;
+----------+
| count(*) |
+----------+
| 33554432 |
+----------+
1 row in set (15.60 sec)
mysql [localhost:8022] {msandbox} (test) > select @@innodb_adaptive_hash_index ;
+------------------------------+
| @@innodb_adaptive_hash_index |
+------------------------------+
| 1 |
+------------------------------+
mysql [localhost:8022] {msandbox} (test) > alter table sales add partition (partition p_2035 values less than (2035));
Query OK, 0 rows affected (0.78 sec)
Records: 0 Duplicates: 0 Warnings: 0
mysql [localhost:8022] {msandbox} (test) > select @@innodb_adaptive_hash_index ;
+------------------------------+
| @@innodb_adaptive_hash_index |
+------------------------------+
| 0 |
+------------------------------+
1 row in set (0.00 sec)
mysql [localhost:8022] {msandbox} (test) > alter table sales1 add partition (partition p_2035 values less than (2035));
Query OK, 0 rows affected (0.17 sec)
Records: 0 Duplicates: 0 Warnings: 0
mysql [localhost:8022] {msandbox} (test) > select @@version;
+-----------+
| @@version |
+-----------+
| 8.0.22 |
+-----------+
1 row in set (0.00 sec)
time with and withouyt adaptive hash index to add the partition is 100% identical
all best
Bogdan
[8 Dec 2020 16:24]
MySQL Verification Team
Hi, Apologies I'm blind 0.17 vs 0.79, that's almost 5x slower! I'll verify this. Thanks for reporting the bug Bogdan
[8 Dec 2020 17:21]
peng gao
Thanks for Bogdan：
In my test 1.6 vs 0.3 ，the same as your result at most 5x slower！
I think the most slowest point is：
->btr_search_drop_page_hash_when_freed
->btr_search_drop_page_hash_index
->rec_fold
->ut_fold_ulint_pair
because every block、every row and every field will calculate fold.
[17 Mar 2022 2:44]
shaoqing sun
mysql version is 8.0.23 Add partition is not only slow, when i kill the running this session, mysql server is down. ASSERTION FAILURE: DICT0DICT.CC:1885:TABLE->GET_REF_COUNT == 0
[17 Mar 2022 2:44]
shaoqing sun
mysql version is 8.0.23 Add partition is not only slow, when i kill the running this session, mysql server is down. ASSERTION FAILURE: DICT0DICT.CC:1885:TABLE->GET_REF_COUNT == 0
[2 Dec 2022 10:05]
Marek Kretkiewicz
Do you have any update for this ?
In our version 8.0.26 we had very similar problem today.
We have table with some transation informations, and we create partitions for each week.
PARTITION p202242 VALUES LESS THAN ('2022-10-17') ENGINE = InnoDB,
PARTITION p202243 VALUES LESS THAN ('2022-10-24') ENGINE = InnoDB,
PARTITION p202244 VALUES LESS THAN ('2022-10-31') ENGINE = InnoDB,
PARTITION p202245 VALUES LESS THAN ('2022-11-07') ENGINE = InnoDB,
PARTITION p202246 VALUES LESS THAN ('2022-11-14') ENGINE = InnoDB,
PARTITION p202247 VALUES LESS THAN ('2022-11-21') ENGINE = InnoDB,
PARTITION p202248 VALUES LESS THAN ('2022-11-28') ENGINE = InnoDB,
PARTITION p202249 VALUES LESS THAN ('2022-12-05') ENGINE = InnoDB,
a month ago we have increased innodb_log_file_size and innodb_buffer_pool_size, and after that alter table exection time has increased above 10s (usualy 12-14s), before it was 3s.
However what is interesting today it was running for ~90s, so decided to stop it, as a consequence mysql server was restarted.
2022-12-02T08:38:06.937369Z 2269171 [ERROR] [MY-013183] [InnoDB] Assertion failure: dict0dict.cc:1882:table->get_ref_count() == 0 thread 139909770733312
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
InnoDB: If you get repeated assertion failures or crashes, even
InnoDB: immediately after the mysqld startup, there may be
InnoDB: corruption in the InnoDB tablespace. Please refer to
InnoDB: http://dev.mysql.com/doc/refman/8.0/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
08:38:06 UTC - mysqld got signal 6 ;
Most likely, you have hit a bug, but this error can also be caused by malfunctioning hardware.
Thread pointer: 0x7f393c0e96c0
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 7f3f482f5c70 thread_stack 0x30000
/usr/sbin/mysqld(my_print_stacktrace(unsigned char const*, unsigned long)+0x3d) [0x20e7edd]
/usr/sbin/mysqld(handle_fatal_signal+0x30b) [0xf387fb]
/lib64/libpthread.so.0(+0xf5d0) [0x7f3fba9ea5d0]
/lib64/libc.so.6(gsignal+0x37) [0x7f3fb8f37207]
/lib64/libc.so.6(abort+0x148) [0x7f3fb8f388f8]
/usr/sbin/mysqld() [0xc76ef0]
/usr/sbin/mysqld() [0x2437668]
/usr/sbin/mysqld(dict_partitioned_table_remove_from_cache(char const*)+0xf8) [0x2437858]
/usr/sbin/mysqld() [0x21cf2c2]
/usr/sbin/mysqld() [0xe8b881]
/usr/sbin/mysqld(mysql_alter_table(THD*, char const*, char const*, HA_CREATE_INFO*, TABLE_LIST*, Alter_info*)+0x7aab) [0xea05db]
/usr/sbin/mysqld(Sql_cmd_alter_table::execute(THD*)+0x4dc) [0x126715c]
/usr/sbin/mysqld(mysql_execute_command(THD*, bool)+0x9c8) [0xdf1ab8]
/usr/sbin/mysqld(dispatch_sql_command(THD*, Parser_state*)+0x40b) [0xdf50cb]
/usr/sbin/mysqld(dispatch_command(THD*, COM_DATA const*, enum_server_command)+0xdda) [0xdf638a]
/usr/sbin/mysqld(do_command(THD*)+0x194) [0xdf8184]
/usr/sbin/mysqld() [0xf29900]
/usr/sbin/mysqld() [0x259ac6e]
/lib64/libpthread.so.0(+0x7dd5) [0x7f3fba9e2dd5]
/lib64/libc.so.6(clone+0x6d) [0x7f3fb8ffeead]
Description: Hi all: at some time,we add a partition .this operation is so slow! any select is hang! like this: mysql> show processlist; +----+-----------------+-----------+------+---------+------+------------------------------------------+----------------------------------------------------------------------------+ | Id | User | Host | db | Command | Time | State | Info | +----+-----------------+-----------+------+---------+------+------------------------------------------+----------------------------------------------------------------------------+ | 5 | event_scheduler | localhost | NULL | Daemon | 165 | Waiting on empty queue | NULL | | 8 | root | localhost | test | Query | 4 | Waiting for table metadata lock | select * from sales | | 10 | root | localhost | test | Query | 25 | committing alter table to storage engine | alter table sales add partition (partition p_2035 values less than (2035)) | | 11 | root | localhost | NULL | Query | 0 | starting | show processlist | +----+-----------------+-----------+------+---------+------+------------------------------------------+----------------------------------------------------------------------------+ 4 rows in set (0.00 sec) mysql> show processlist; +----+-----------------+-----------+------+---------+------+------------------------------------------+----------------------------------------------------------------------------+ | Id | User | Host | db | Command | Time | State | Info | +----+-----------------+-----------+------+---------+------+------------------------------------------+----------------------------------------------------------------------------+ | 5 | event_scheduler | localhost | NULL | Daemon | 185 | Waiting on empty queue | NULL | | 8 | root | localhost | test | Query | 3 | Waiting for table metadata lock | select * from sales partition(p_2019) | | 10 | root | localhost | test | Query | 45 | committing alter table to storage engine | alter table sales add partition (partition p_2035 values less than (2035)) | | 11 | root | localhost | NULL | Query | 0 | starting | show processlist | +----+-----------------+-----------+------+---------+------+------------------------------------------+----------------------------------------------------------------------------+ The stack like : (gdb) bt #0 0x0000000004fa1e73 in rec_offs_n_fields (offsets=0xb479910) at /opt/mysql/mysql-8.0.21/storage/innobase/rem/rec.h:449 #1 0x0000000004fa3d82 in rec_offs_data_size (offsets=0xb479910) at /opt/mysql/mysql-8.0.21/storage/innobase/include/rem0rec.ic:935 #2 0x0000000004fa7ad1 in rec_validate (rec=0x7fff450e7516 "", offsets=0xb479910) at /opt/mysql/mysql-8.0.21/storage/innobase/rem/rem0rec.cc:1337 #3 0x000000000519eeea in rec_fold (rec=0x7fff450e7516 "", offsets=0xb479910, n_fields=0, n_bytes=1, fold=108872348850564, index=0xb46d900) at /opt/mysql/mysql-8.0.21/storage/innobase/include/rem0rec.ic:1122 #4 0x00000000051a32e1 in btr_search_drop_page_hash_index (block=0x7fff4352f158) at /opt/mysql/mysql-8.0.21/storage/innobase/btr/btr0sea.cc:1177 #5 0x00000000051a38c3 in btr_search_drop_page_hash_when_freed (page_id=..., page_size=...) at /opt/mysql/mysql-8.0.21/storage/innobase/btr/btr0sea.cc:1275 #6 0x00000000051a3d23 in btr_drop_ahi_for_table (table=0xb46bc10) at /opt/mysql/mysql-8.0.21/storage/innobase/btr/btr0sea.cc:1354 #7 0x0000000004e61295 in alter_part_normal::try_commit (this=0xbaadc30, table=0x0, altered_table=0xbb75500, old_part=0xb474738, new_part=0xbb293c8) at /opt/mysql/mysql-8.0.21/storage/innobase/handler/handler0alter.cc:8550 #8 0x0000000004e4cdd5 in alter_parts::prepare_or_commit_for_new (this=0xb97f240, old_dd_tab=..., new_dd_tab=..., altered_table=0xbb75500, prepare=false) at /opt/mysql/mysql-8.0.21/storage/innobase/handler/handler0alter.cc:9657 #9 0x0000000004e4c6fe in alter_parts::try_commit (this=0xb97f240, old_dd_tab=..., new_dd_tab=..., table=0xaaef7b0, altered_table=0xbb75500) at /opt/mysql/mysql-8.0.21/storage/innobase/handler/handler0alter.cc:9584 #10 0x0000000004e4f83e in ha_innopart::commit_inplace_alter_partition (this=0xb47a018, altered_table=0xbb75500, ha_alter_info=0x7fff602dc670, commit=true, old_dd_tab=0xaaf06e8, new_dd_tab=0xb924368) at /opt/mysql/mysql-8.0.21/storage/innobase/handler/handler0alter.cc:10515 #11 0x0000000004e4e8ee in ha_innopart::commit_inplace_alter_table (this=0xb47a018, altered_table=0xbb75500, ha_alter_info=0x7fff602dc670, commit=true, old_table_def=0xaaf06e8, new_table_def=0xb924368) at /opt/mysql/mysql-8.0.21/storage/innobase/handler/handler0alter.cc:10216 #12 0x0000000003ad89a3 in handler::ha_commit_inplace_alter_table (this=0xb47a018, altered_table=0xbb75500, ha_alter_info=0x7fff602dc670, commit=true, old_table_def=0xaaf06e8, new_table_def=0xb924368) at /opt/mysql/mysql-8.0.21/sql/handler.cc:4885 I think this operation is AHI maintain, when AHI rows is large this operation is slow,But this operation is protect by mdl x at DDL commit stage,so select is hang! How to avoid this ? set AHI OFF? thanks!! How to repeat: 1. CREATE TABLE `sales` ( `order_date` datetime NOT NULL, `id` int DEFAULT NULL ) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_0900_ai_ci /*!50100 PARTITION BY RANGE (year(`order_date`)) (PARTITION P_2017 VALUES LESS THAN (2017) ENGINE = InnoDB, PARTITION P_2018 VALUES LESS THAN (2018) ENGINE = InnoDB, PARTITION p_2019 VALUES LESS THAN (2019) ENGINE = InnoDB, PARTITION p_2020 VALUES LESS THAN (2020) ENGINE = InnoDB, PARTITION p_2021 VALUES LESS THAN (2021) ENGINE = InnoDB */; 2. insert 500W data 3. alter table sales add partition (partition p_2035 values less than (2035)); 4. when innodb_adaptive_hash_index set OFF,add partition is not slow!! Suggested fix: no Suggest