Details
-
Bug
-
Status: Closed (View Workflow)
-
Major
-
Resolution: Incomplete
-
10.1.34
Description
After upgrade from 10.1.30 to 10.1.34 (10.1.40 affected too) we discovery that drop table locks many queries like 'show create table ....' on working server (15-25 Krps).
Drop of just created table works unexpected long for table about 250Krows, 80 Mb on server with SSD and big buffer pool (140Gb and 400Gb):
- about 0.1 sec on empty 140G buffer pool (after start)
- about 1 sec on full 140G buffer pool
- about 3 sec on full 400G buffer pool
Script to reproduce:
#!/bin/bash
|
|
tmp=`mktemp`
|
tmp1=`mktemp`
|
tmp2=`mktemp`
|
|
mysql -h server >$tmp <<EOF
|
use tmp;
|
drop table if exists sss1, sss2, sss3;
|
create table sss1 like search.company_search_summary_table;
|
insert into sss1 select * from search.company_search_summary_table ;
|
EOF
|
|
|
(
|
mysql -t -h server >$tmp1 <<EOF
|
select "drop";
|
set profiling = 1;
|
drop table tmp.sss1;
|
show profile source;
|
status;
|
EOF
|
) &
|
|
(
|
mysql -t -h server >$tmp2 <<EOF
|
set profiling = 1;
|
show create table sys.date_time;
|
show profile source;
|
show create table sys.date_time;
|
show profile source;
|
show create table sys.date_time;
|
show profile source;
|
show create table sys.date_time;
|
show profile source;
|
status;
|
EOF
|
) &
|
|
|
wait
|
head -n400 $tmp $tmp1 $tmp2
|
/bin/rm -f $tmp $tmp1 $tmp2
|
Output
$ cat /tmp/aa
|
==> /tmp/tmp.Fn4nIpaTFj <==
|
|
|
==> /tmp/tmp.L9qGfzb24e <==
|
+------+
|
| drop |
|
+------+
|
| drop |
|
+------+
|
+----------------------+----------+-----------------------+--------------+-------------+
|
| Status | Duration | Source_function | Source_file | Source_line |
|
+----------------------+----------+-----------------------+--------------+-------------+
|
| starting | 0.000035 | NULL | NULL | NULL |
|
| checking permissions | 0.000028 | check_access | sql_parse.cc | 6154 |
|
| Opening tables | 0.000039 | open_tables | sql_base.cc | 4532 |
|
| After opening tables | 0.000024 | open_tables | sql_base.cc | 4779 |
|
| System lock | 0.000024 | mysql_lock_tables | lock.cc | 308 |
|
| Table lock | 0.000066 | mysql_lock_tables | lock.cc | 313 |
|
| closing tables | 0.000023 | close_thread_tables | sql_base.cc | 919 |
|
| Unlocking tables | 1.101685 | mysql_unlock_tables | lock.cc | 396 |
|
| query end | 0.000102 | mysql_execute_command | sql_parse.cc | 5706 |
|
| closing tables | 0.000059 | close_thread_tables | sql_base.cc | 919 |
|
| freeing items | 0.000050 | mysql_parse | sql_parse.cc | 7466 |
|
| updating status | 0.000062 | dispatch_command | sql_parse.cc | 1954 |
|
| cleaning up | 0.000049 | dispatch_command | sql_parse.cc | 1973 |
|
+----------------------+----------+-----------------------+--------------+-------------+
|
--------------
|
mysql Ver 15.1 Distrib 10.1.37-MariaDB, for debian-linux-gnu (x86_64) using readline 5.2
|
|
|
Connection id: 3742891
|
Current database:
|
Current user: user@10.10.8.36
|
SSL: Not in use
|
Current pager: stdout
|
Using outfile: ''
|
Using delimiter: ;
|
Server: MariaDB
|
Server version: 10.1.34-MariaDB MariaDB Server
|
Protocol version: 10
|
Connection: server via TCP/IP
|
Server characterset: utf8
|
Db characterset: utf8
|
Client characterset: utf8
|
Conn. characterset: utf8
|
TCP port: 3306
|
Uptime: 42 min 35 sec
|
|
|
Threads: 688 Questions: 55997878 Slow queries: 0 Opens: 8070 Flush tables: 1 Open tables: 2033 Queries per second avg: 21916.977
|
--------------
|
|
|
|
|
==> /tmp/tmp.RX2wgWmf9w <==
|
+-----------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
|
| Table | Create Table |
|
+-----------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
|
| date_time | CREATE TABLE `date_time` (
|
`date` int(10) unsigned NOT NULL DEFAULT '0',
|
`name` varchar(255) NOT NULL DEFAULT 'unknown',
|
PRIMARY KEY (`name`)
|
) ENGINE=InnoDB DEFAULT CHARSET=utf8 ROW_FORMAT=DYNAMIC |
|
+-----------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
|
+----------------------+----------+-----------------------+--------------+-------------+
|
| Status | Duration | Source_function | Source_file | Source_line |
|
+----------------------+----------+-----------------------+--------------+-------------+
|
| starting | 0.000084 | NULL | NULL | NULL |
|
| checking permissions | 0.000041 | check_access | sql_parse.cc | 6154 |
|
| Opening tables | 0.000036 | open_tables | sql_base.cc | 4532 |
|
| After opening tables | 0.000044 | open_tables | sql_base.cc | 4779 |
|
| closing tables | 0.000042 | close_thread_tables | sql_base.cc | 919 |
|
| query end | 0.000025 | mysql_execute_command | sql_parse.cc | 5706 |
|
| closing tables | 0.000024 | close_thread_tables | sql_base.cc | 919 |
|
| freeing items | 0.000030 | mysql_parse | sql_parse.cc | 7466 |
|
| updating status | 0.000034 | dispatch_command | sql_parse.cc | 1954 |
|
| cleaning up | 0.000037 | dispatch_command | sql_parse.cc | 1973 |
|
+----------------------+----------+-----------------------+--------------+-------------+
|
+-----------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
|
| Table | Create Table |
|
+-----------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
|
| date_time | CREATE TABLE `date_time` (
|
`date` int(10) unsigned NOT NULL DEFAULT '0',
|
`name` varchar(255) NOT NULL DEFAULT 'unknown',
|
PRIMARY KEY (`name`)
|
) ENGINE=InnoDB DEFAULT CHARSET=utf8 ROW_FORMAT=DYNAMIC |
|
+-----------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
|
+----------------------+----------+-----------------------+--------------+-------------+
|
| Status | Duration | Source_function | Source_file | Source_line |
|
+----------------------+----------+-----------------------+--------------+-------------+
|
| starting | 0.000039 | NULL | NULL | NULL |
|
| checking permissions | 0.000025 | check_access | sql_parse.cc | 6154 |
|
| Opening tables | 0.000027 | open_tables | sql_base.cc | 4532 |
|
| After opening tables | 1.100046 | open_tables | sql_base.cc | 4779 |
|
| closing tables | 0.000155 | close_thread_tables | sql_base.cc | 919 |
|
| query end | 0.000103 | mysql_execute_command | sql_parse.cc | 5706 |
|
| closing tables | 0.000060 | close_thread_tables | sql_base.cc | 919 |
|
| freeing items | 0.000051 | mysql_parse | sql_parse.cc | 7466 |
|
| updating status | 0.000072 | dispatch_command | sql_parse.cc | 1954 |
|
| cleaning up | 0.000068 | dispatch_command | sql_parse.cc | 1973 |
|
+----------------------+----------+-----------------------+--------------+-------------+
|
+-----------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
|
| Table | Create Table |
|
+-----------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
|
| date_time | CREATE TABLE `date_time` (
|
`date` int(10) unsigned NOT NULL DEFAULT '0',
|
`name` varchar(255) NOT NULL DEFAULT 'unknown',
|
PRIMARY KEY (`name`)
|
) ENGINE=InnoDB DEFAULT CHARSET=utf8 ROW_FORMAT=DYNAMIC |
|
+-----------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
|
+----------------------+----------+-----------------------+--------------+-------------+
|
| Status | Duration | Source_function | Source_file | Source_line |
|
+----------------------+----------+-----------------------+--------------+-------------+
|
| starting | 0.000090 | NULL | NULL | NULL |
|
| checking permissions | 0.000047 | check_access | sql_parse.cc | 6154 |
|
| Opening tables | 0.000043 | open_tables | sql_base.cc | 4532 |
|
| After opening tables | 0.084826 | open_tables | sql_base.cc | 4779 |
|
| closing tables | 0.000127 | close_thread_tables | sql_base.cc | 919 |
|
| query end | 0.000054 | mysql_execute_command | sql_parse.cc | 5706 |
|
| closing tables | 0.000041 | close_thread_tables | sql_base.cc | 919 |
|
| freeing items | 0.000036 | mysql_parse | sql_parse.cc | 7466 |
|
| updating status | 0.000066 | dispatch_command | sql_parse.cc | 1954 |
|
| cleaning up | 0.000053 | dispatch_command | sql_parse.cc | 1973 |
|
+----------------------+----------+-----------------------+--------------+-------------+
|
+-----------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
|
| Table | Create Table |
|
+-----------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
|
| date_time | CREATE TABLE `date_time` (
|
`date` int(10) unsigned NOT NULL DEFAULT '0',
|
`name` varchar(255) NOT NULL DEFAULT 'unknown',
|
PRIMARY KEY (`name`)
|
) ENGINE=InnoDB DEFAULT CHARSET=utf8 ROW_FORMAT=DYNAMIC |
|
+-----------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
|
+----------------------+----------+-----------------------+--------------+-------------+
|
| Status | Duration | Source_function | Source_file | Source_line |
|
+----------------------+----------+-----------------------+--------------+-------------+
|
| starting | 0.000356 | NULL | NULL | NULL |
|
| checking permissions | 0.000059 | check_access | sql_parse.cc | 6154 |
|
| Opening tables | 0.000050 | open_tables | sql_base.cc | 4532 |
|
| After opening tables | 0.000103 | open_tables | sql_base.cc | 4779 |
|
| closing tables | 0.000048 | close_thread_tables | sql_base.cc | 919 |
|
| query end | 0.000039 | mysql_execute_command | sql_parse.cc | 5706 |
|
| closing tables | 0.000039 | close_thread_tables | sql_base.cc | 919 |
|
| freeing items | 0.000043 | mysql_parse | sql_parse.cc | 7466 |
|
| updating status | 0.000054 | dispatch_command | sql_parse.cc | 1954 |
|
| cleaning up | 0.000050 | dispatch_command | sql_parse.cc | 1973 |
|
+----------------------+----------+-----------------------+--------------+-------------+
|
--------------
|
mysql Ver 15.1 Distrib 10.1.37-MariaDB, for debian-linux-gnu (x86_64) using readline 5.2
|
|
|
Connection id: 3742892
|
Current database:
|
Current user: user@10.10.8.36
|
SSL: Not in use
|
Current pager: stdout
|
Using outfile: ''
|
Using delimiter: ;
|
Server: MariaDB
|
Server version: 10.1.34-MariaDB MariaDB Server
|
Protocol version: 10
|
Connection: server via TCP/IP
|
Server characterset: utf8
|
Db characterset: utf8
|
Client characterset: utf8
|
Conn. characterset: utf8
|
TCP port: 3306
|
Uptime: 42 min 35 sec
|
|
|
Threads: 462 Questions: 56002787 Slow queries: 0 Opens: 8070 Flush tables: 1 Open tables: 2033 Queries per second avg: 21918.899
|
--------------
|
One of 'show create' locks on 1 seconds (10.1.34-NN - files with results of serveral script calling):
# egrep 'After|unlock|Uptime' 10.1.34-*
|
10.1.34-82:| After opening tables | 0.000033 | open_tables | sql_base.cc | 4779 |
|
10.1.34-82:| Unlocking tables | 1.117436 | mysql_unlock_tables | lock.cc | 396 |
|
10.1.34-82:Uptime: 41 min 35 sec
|
10.1.34-82:| After opening tables | 0.000035 | open_tables | sql_base.cc | 4779 |
|
10.1.34-82:| After opening tables | 0.000029 | open_tables | sql_base.cc | 4779 |
|
10.1.34-82:| After opening tables | 0.000051 | open_tables | sql_base.cc | 4779 |
|
10.1.34-82:| After opening tables | 1.113856 | open_tables | sql_base.cc | 4779 |
|
10.1.34-82:Uptime: 41 min 35 sec
|
|
|
10.1.34-83:| After opening tables | 0.000039 | open_tables | sql_base.cc | 4779 |
|
10.1.34-83:| Unlocking tables | 1.100278 | mysql_unlock_tables | lock.cc | 396 |
|
10.1.34-83:Uptime: 42 min 5 sec
|
10.1.34-83:| After opening tables | 1.098836 | open_tables | sql_base.cc | 4779 |
|
10.1.34-83:| After opening tables | 0.089455 | open_tables | sql_base.cc | 4779 |
|
10.1.34-83:| After opening tables | 0.000078 | open_tables | sql_base.cc | 4779 |
|
10.1.34-83:| After opening tables | 0.000076 | open_tables | sql_base.cc | 4779 |
|
10.1.34-83:Uptime: 42 min 5 sec
|
|
|
10.1.34-84:| After opening tables | 0.000024 | open_tables | sql_base.cc | 4779 |
|
10.1.34-84:| Unlocking tables | 1.101685 | mysql_unlock_tables | lock.cc | 396 |
|
10.1.34-84:Uptime: 42 min 35 sec
|
10.1.34-84:| After opening tables | 0.000044 | open_tables | sql_base.cc | 4779 |
|
10.1.34-84:| After opening tables | 1.100046 | open_tables | sql_base.cc | 4779 |
|
10.1.34-84:| After opening tables | 0.084826 | open_tables | sql_base.cc | 4779 |
|
10.1.34-84:| After opening tables | 0.000103 | open_tables | sql_base.cc | 4779 |
|
10.1.34-84:Uptime: 42 min 35 sec
|
On version 10.1.33 max time not so high:
10.1.33-96:| After opening tables | 0.000024 | open_tables | sql_base.cc | 4769 |
|
10.1.33-96:| Unlocking tables | 0.131976 | mysql_unlock_tables | lock.cc | 396 |
|
10.1.33-96:Uptime: 49 min 35 sec
|
10.1.33-96:| After opening tables | 0.000038 | open_tables | sql_base.cc | 4769 |
|
10.1.33-96:| After opening tables | 0.032584 | open_tables | sql_base.cc | 4769 |
|
10.1.33-96:| After opening tables | 0.000044 | open_tables | sql_base.cc | 4769 |
|
10.1.33-96:| After opening tables | 0.000038 | open_tables | sql_base.cc | 4769 |
|
10.1.33-96:Uptime: 49 min 34 sec
|
10.1.33-97:| After opening tables | 0.000022 | open_tables | sql_base.cc | 4769 |
|
10.1.33-97:| Unlocking tables | 0.035330 | mysql_unlock_tables | lock.cc | 396 |
|
10.1.33-97:Uptime: 50 min 1 sec
|
10.1.33-97:| After opening tables | 0.000051 | open_tables | sql_base.cc | 4769 |
|
10.1.33-97:| After opening tables | 0.027047 | open_tables | sql_base.cc | 4769 |
|
10.1.33-97:| After opening tables | 0.000030 | open_tables | sql_base.cc | 4769 |
|
10.1.33-97:| After opening tables | 0.000044 | open_tables | sql_base.cc | 4769 |
|
10.1.33-97:Uptime: 50 min 1 sec
|
10.1.33-98:| After opening tables | 0.000023 | open_tables | sql_base.cc | 4769 |
|
10.1.33-98:| Unlocking tables | 0.141847 | mysql_unlock_tables | lock.cc | 396 |
|
10.1.33-98:Uptime: 50 min 27 sec
|
10.1.33-98:| After opening tables | 0.000040 | open_tables | sql_base.cc | 4769 |
|
10.1.33-98:| After opening tables | 0.031896 | open_tables | sql_base.cc | 4769 |
|
10.1.33-98:| After opening tables | 0.000036 | open_tables | sql_base.cc | 4769 |
|
10.1.33-98:| After opening tables | 0.000063 | open_tables | sql_base.cc | 4769 |
|
10.1.33-98:Uptime: 50 min 27 sec
|
10.1.33-99:| After opening tables | 0.000041 | open_tables | sql_base.cc | 4769 |
|
10.1.33-99:| Unlocking tables | 0.042536 | mysql_unlock_tables | lock.cc | 396 |
|
10.1.33-99:Uptime: 50 min 54 sec
|
10.1.33-99:| After opening tables | 0.000045 | open_tables | sql_base.cc | 4769 |
|
10.1.33-99:| After opening tables | 0.000040 | open_tables | sql_base.cc | 4769 |
|
10.1.33-99:| After opening tables | 0.000039 | open_tables | sql_base.cc | 4769 |
|
10.1.33-99:| After opening tables | 0.000033 | open_tables | sql_base.cc | 4769 |
|
10.1.33-99:Uptime: 50 min 55 sec
|
MariaDB [search]> show table status like 'company_search_summary_table'\G
|
*************************** 1. row ***************************
|
Name: company_search_summary_table
|
Engine: InnoDB
|
Version: 10
|
Row_format: Compact
|
Rows: 267016
|
Avg_row_length: 332
|
Data_length: 88719360
|
Max_data_length: 0
|
Index_length: 0
|
Data_free: 6291456
|
Auto_increment: NULL
|
Create_time: 2019-05-22 16:21:40
|
Update_time: NULL
|
Check_time: NULL
|
Collation: utf8_general_ci
|
Checksum: NULL
|
Create_options:
|
Comment:
|
This server has 140G buffer pool, on out main server with buffer pool 400G locks duration more than 3 seconds.
Attachments
Issue Links
- relates to
-
-
- Closed
-
Activity
@Marko Mäkelä, I use INSERT..SELECT here only to fill table, DROP TABLE and SHOW CREATE... executed after INSERT..SELECT.
And important thing: DROP big TABLE locking other queries for other tables. We drop table A and SHOW CREATE TABLE for table B is locked between "After opening tables" and "closing table".
If I drop table which used recently - other queries will be locked. If I drop table which does not used several hours (and evicted from buffer pool) when other queries will not be locked. So now we renaming tables to temporary schema and drop such tables at night to avoid locks.
Is it need to test MDEV-14479? I think record locks are not couse of this problem.
I've tested 10.5.2
MariaDB [tmp]> show table status like 'sss1'\G;
|
*************************** 1. row ***************************
|
Name: sss1
|
Engine: InnoDB
|
Version: 10
|
Row_format: Dynamic
|
Rows: 337106
|
Avg_row_length: 166
|
Data_length: 56164352
|
Max_data_length: 0
|
Index_length: 0
|
Data_free: 7340032
|
Auto_increment: NULL
|
Create_time: 2020-04-16 22:13:25
|
Update_time: 2020-04-16 22:13:28
|
Check_time: NULL
|
Collation: utf8_general_ci
|
Checksum: NULL
|
Create_options:
|
Comment:
|
Max_index_length: 0
|
Temporary: N
|
1 row in set (0.01 sec)
|
drop table sss1
+------------------------+----------+-----------------+--------------+-------------+
|
| Status | Duration | Source_function | Source_file | Source_line |
|
+------------------------+----------+-----------------+--------------+-------------+
|
| Starting | 0.000032 | NULL | NULL | NULL |
|
| checking permissions | 0.000017 | <unknown> | sql_parse.cc | 6619 |
|
| Opening tables | 0.000030 | <unknown> | sql_base.cc | 4245 |
|
| After opening tables | 0.000008 | <unknown> | sql_base.cc | 4502 |
|
| System lock | 0.000017 | <unknown> | lock.cc | 336 |
|
| table lock | 0.000020 | <unknown> | lock.cc | 341 |
|
| closing tables | 0.000009 | <unknown> | sql_base.cc | 873 |
|
| Unlocking tables | 0.000018 | <unknown> | lock.cc | 427 |
|
| closing tables | 0.016854 | <unknown> | lock.cc | 440 |
|
| Query end | 0.000010 | <unknown> | sql_parse.cc | 5920 |
|
| Commit | 0.000008 | <unknown> | sql_parse.cc | 5965 |
|
| closing tables | 0.000007 | <unknown> | sql_base.cc | 873 |
|
| Commit implicit | 0.000011 | <unknown> | sql_parse.cc | 6006 |
|
| Starting cleanup | 0.000009 | <unknown> | sql_parse.cc | 6034 |
|
| Freeing items | 0.000009 | <unknown> | sql_parse.cc | 7970 |
|
| Updating status | 0.000015 | <unknown> | sql_parse.cc | 2425 |
|
| Reset for next command | 0.000012 | <unknown> | sql_parse.cc | 2449 |
|
+------------------------+----------+-----------------+--------------+-------------+
|
At same time one of many queries SHOW CREATE TABLE sys.date_time
+------------------------+----------+-----------------+--------------+-------------+
|
| Status | Duration | Source_function | Source_file | Source_line |
|
+------------------------+----------+-----------------+--------------+-------------+
|
| Starting | 0.000019 | NULL | NULL | NULL |
|
| checking permissions | 0.000006 | <unknown> | sql_parse.cc | 6619 |
|
| Opening tables | 0.000009 | <unknown> | sql_base.cc | 4245 |
|
| After opening tables | 0.016512 | <unknown> | sql_base.cc | 4502 |
|
| closing tables | 0.000037 | <unknown> | sql_base.cc | 873 |
|
| Query end | 0.000009 | <unknown> | sql_parse.cc | 5920 |
|
| Commit | 0.000009 | <unknown> | sql_parse.cc | 5965 |
|
| closing tables | 0.000010 | <unknown> | sql_base.cc | 873 |
|
| Starting cleanup | 0.000008 | <unknown> | sql_parse.cc | 6034 |
|
| Freeing items | 0.000009 | <unknown> | sql_parse.cc | 7970 |
|
| Updating status | 0.000017 | <unknown> | sql_parse.cc | 2425 |
|
| Reset for next command | 0.000014 | <unknown> | sql_parse.cc | 2449 |
|
+------------------------+----------+-----------------+--------------+-------------+
|
other queries looks like this:
+------------------------+----------+-----------------+--------------+-------------+
|
| Status | Duration | Source_function | Source_file | Source_line |
|
+------------------------+----------+-----------------+--------------+-------------+
|
| Starting | 0.000021 | NULL | NULL | NULL |
|
| checking permissions | 0.000008 | <unknown> | sql_parse.cc | 6619 |
|
| Opening tables | 0.000010 | <unknown> | sql_base.cc | 4245 |
|
| After opening tables | 0.000013 | <unknown> | sql_base.cc | 4502 |
|
| closing tables | 0.000008 | <unknown> | sql_base.cc | 873 |
|
| Query end | 0.000011 | <unknown> | sql_parse.cc | 5920 |
|
| Commit | 0.000012 | <unknown> | sql_parse.cc | 5965 |
|
| closing tables | 0.000005 | <unknown> | sql_base.cc | 873 |
|
| Starting cleanup | 0.000005 | <unknown> | sql_parse.cc | 6034 |
|
| Freeing items | 0.000012 | <unknown> | sql_parse.cc | 7970 |
|
| Updating status | 0.000017 | <unknown> | sql_parse.cc | 2425 |
|
| Reset for next command | 0.000013 | <unknown> | sql_parse.cc | 2449 |
|
+------------------------+----------+-----------------+--------------+-------------+
|
|
|
+------------------------+----------+-----------------+--------------+-------------+
|
| Status | Duration | Source_function | Source_file | Source_line |
|
+------------------------+----------+-----------------+--------------+-------------+
|
| Starting | 0.000030 | NULL | NULL | NULL |
|
| checking permissions | 0.000013 | <unknown> | sql_parse.cc | 6619 |
|
| Opening tables | 0.000014 | <unknown> | sql_base.cc | 4245 |
|
| After opening tables | 0.000019 | <unknown> | sql_base.cc | 4502 |
|
| closing tables | 0.000010 | <unknown> | sql_base.cc | 873 |
|
| Query end | 0.000005 | <unknown> | sql_parse.cc | 5920 |
|
| Commit | 0.000006 | <unknown> | sql_parse.cc | 5965 |
|
| closing tables | 0.000006 | <unknown> | sql_base.cc | 873 |
|
| Starting cleanup | 0.000005 | <unknown> | sql_parse.cc | 6034 |
|
| Freeing items | 0.000006 | <unknown> | sql_parse.cc | 7970 |
|
| Updating status | 0.000009 | <unknown> | sql_parse.cc | 2425 |
|
| Reset for next command | 0.000020 | <unknown> | sql_parse.cc | 2449 |
|
+------------------------+----------+-----------------+--------------+-------------+
|
+------------------------+----------+-----------------+--------------+-------------+
|
| Status | Duration | Source_function | Source_file | Source_line |
|
+------------------------+----------+-----------------+--------------+-------------+
|
| Starting | 0.000017 | NULL | NULL | NULL |
|
| checking permissions | 0.000013 | <unknown> | sql_parse.cc | 6619 |
|
| Opening tables | 0.000022 | <unknown> | sql_base.cc | 4245 |
|
| After opening tables | 0.000021 | <unknown> | sql_base.cc | 4502 |
|
| closing tables | 0.000015 | <unknown> | sql_base.cc | 873 |
|
| Query end | 0.000016 | <unknown> | sql_parse.cc | 5920 |
|
| Commit | 0.000017 | <unknown> | sql_parse.cc | 5965 |
|
| closing tables | 0.000015 | <unknown> | sql_base.cc | 873 |
|
| Starting cleanup | 0.000017 | <unknown> | sql_parse.cc | 6034 |
|
| Freeing items | 0.000016 | <unknown> | sql_parse.cc | 7970 |
|
| Updating status | 0.000022 | <unknown> | sql_parse.cc | 2425 |
|
| Reset for next command | 0.000015 | <unknown> | sql_parse.cc | 2449 |
|
+------------------------+----------+-----------------+--------------+-------------+
|
Total large memory allocated 430033600512
|
Dictionary memory allocated 2551692312
|
Buffer pool size 25683200
|
Free buffers 1024
|
Database pages 26413493
|
Old database pages 9750273
|
Modified db pages 3354
|
I see the same problem: other processes locks when some table is dropping. These tables (dropping and reading) are different tables.
Yes, dropping is very fast now and locks are fast. But is it normal situation when droping one table locks all other processes with another tables?
Now on 10.3.17 dropping big recent used table (about 200gb on disk) may lasts 20-30 seconds and more...
Probably your problem was fixed in https://github.com/MariaDB/server/commit/264a98eaa0a783e1ce76d18b9105ae00dc11098b A new release with that patch should appear soon.
Could you provide more info?
Specifically could you try to catch a long unlink() via strace and somehow check that it's the reason for blocking?
Built-in trace is very imprecise. Could you try perf or BPF trace + https://github.com/brendangregg/FlameGraph ? http://www.brendangregg.com/blog/2016-10-21/linux-efficient-profiler.html Function names are a must in such a trace! If you use Debian/Ubuntu you might need to install a separate package to see function names.
chernomorets, can you reproduce this in MariaDB Server 10.5.4 or later?
chernomorets, I just noticed this bug.
In InnoDB, INSERT…SELECT is unfortunate in that it will create an explicit lock for every InnoDB index record visited by the SELECT part of the statement. I wonder if all your problems are related to that?
Can you try creating the source table in some other table than InnoDB?
MDEV-14479could provide some help to this, allowing you to use LOCK TABLE to prevent the explicit record locks from being created. Could you please try that as well?