[MDEV-11132] Extra locking upon concurrent DDL/DML Created: 2016-10-25  Updated: 2020-12-17

Status: Open
Project: MariaDB Server
Component/s: Locking
Affects Version/s: 10.0, 10.1, 10.2
Fix Version/s: 10.2

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Vladislav Vaintroub
Resolution: Unresolved Votes: 1
Labels: None


 Description   

In the 2-thread flow produced by the test below, on 10.x both threads get locked soon after start. It is not a total deadlock, it is controlled by lock_wait_timeout; but it doesn't happen on 5.5 or MySQL 5.6, 5.7; so, possibly the threads take or want more locks than they should have.

Process list

+----+------+-----------------+-------+---------+------+---------------------------------+-----------------------------------------------------------------------+----------+
| Id | User | Host            | db    | Command | Time | State                           | Info                                                                  | Progress |
+----+------+-----------------+-------+---------+------+---------------------------------+-----------------------------------------------------------------------+----------+
|  2 | rqg  | localhost:60719 | mysql | Sleep   |  169 |                                 | NULL                                                                  |    0.000 |
|  6 | rqg  | localhost:60725 | test  | Query   |  168 | Waiting for table metadata lock | ALTER TABLE `db`.`t2` COMMENT = 'UPDATED' /* QNO 23 CON_ID 6 */       |    0.000 |
|  7 | rqg  | localhost:60728 | test  | Query   |  168 | Waiting for table level lock    | INSERT INTO `db`.`t2` SELECT * FROM `test`.`t1` /* QNO 22 CON_ID 7 */ |    0.000 |
|  8 | root | localhost:39071 | test  | Query   |    0 | init                            | show full processlist                                                 |    0.000 |
+----+------+-----------------+-------+---------+------+---------------------------------+-----------------------------------------------------------------------+----------+

Metadata lock info

+-----------+-------------------------+---------------+----------------------+--------------+------------+
| THREAD_ID | LOCK_MODE               | LOCK_DURATION | LOCK_TYPE            | TABLE_SCHEMA | TABLE_NAME |
+-----------+-------------------------+---------------+----------------------+--------------+------------+
|         6 | MDL_SHARED_UPGRADABLE   | NULL          | Table metadata lock  | db           | t2         |
|         6 | MDL_INTENTION_EXCLUSIVE | NULL          | Schema metadata lock | db           |            |
|         6 | MDL_INTENTION_EXCLUSIVE | NULL          | Global read lock     |              |            |
|         7 | MDL_INTENTION_EXCLUSIVE | NULL          | Global read lock     |              |            |
|         7 | MDL_SHARED_READ         | NULL          | Table metadata lock  | test         | t1         |
|         7 | MDL_SHARED_WRITE        | NULL          | Table metadata lock  | db           | t2         |
+-----------+-------------------------+---------------+----------------------+--------------+------------+

Stack traces from both threads, 10.0 fb38d26420

Thread 3 (Thread 0x7f53d335b700 (LWP 10014)):
#0  pthread_cond_timedwait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:238
#1  0x0000000000e247c4 in safe_cond_timedwait (cond=0x7f53b8dbd218, mp=0x7f53b8dbd168, abstime=0x7f53d33578f0, file=0xebfe00 "/data/src/10.0/
include/mysql/psi/mysql_thread.h", line=1202) at /data/src/10.0/mysys/thr_mutex.c:547
#2  0x000000000076a8c0 in inline_mysql_cond_timedwait (that=0x7f53b8dbd218, mutex=0x7f53b8dbd168, abstime=0x7f53d33578f0, src_file=0xec0062 "
/data/src/10.0/sql/mdl.cc", src_line=1439) at /data/src/10.0/include/mysql/psi/mysql_thread.h:1202
#3  0x000000000076bd54 in MDL_wait::timed_wait (this=0x7f53b8dbd168, owner=0x7f53b8dbd120, abs_timeout=0x7f53d33578f0, set_status_on_timeout=
false, wait_state_name=0x15b9370 <MDL_key::m_namespace_to_wait_state_name+48>) at /data/src/10.0/sql/mdl.cc:1439
#4  0x000000000076d276 in MDL_context::acquire_lock (this=0x7f53b8dbd168, mdl_request=0x7f53d33579a0, lock_wait_timeout=31536000) at /data/sr
c/10.0/sql/mdl.cc:2440
#5  0x000000000076d97d in MDL_context::upgrade_shared_lock (this=0x7f53b8dbd168, mdl_ticket=0x7f53a8135100, new_type=MDL_EXCLUSIVE, lock_wait
_timeout=31536000) at /data/src/10.0/sql/mdl.cc:2633
#6  0x00000000005e5fab in wait_while_table_is_used (thd=0x7f53b8dbd070, table=0x7f53a68ed870, function=HA_EXTRA_PREPARE_FOR_RENAME) at /data/
src/10.0/sql/sql_base.cc:1823
#7  0x00000000006fab10 in mysql_inplace_alter_table (thd=0x7f53b8dbd070, table_list=0x7f53a83111c8, table=0x7f53a68ed870, altered_table=0x7f5
3be7fe070, ha_alter_info=0x7f53d33582c0, inplace_supported=HA_ALTER_INPLACE_NO_LOCK, target_mdl_request=0x7f53d3357d10, alter_ctx=0x7f53d3358
8a0) at /data/src/10.0/sql/sql_table.cc:7100
#8  0x00000000006ff019 in mysql_alter_table (thd=0x7f53b8dbd070, new_db=0x7f53a8311180 "db", new_name=0x0, create_info=0x7f53d3359540, table_
list=0x7f53a83111c8, alter_info=0x7f53d33594b0, order_num=0, order=0x0, ignore=false) at /data/src/10.0/sql/sql_table.cc:8885
#9  0x000000000076681d in Sql_cmd_alter_table::execute (this=0x7f53a83117c8, thd=0x7f53b8dbd070) at /data/src/10.0/sql/sql_alter.cc:312
#10 0x000000000064ea6d in mysql_execute_command (thd=0x7f53b8dbd070) at /data/src/10.0/sql/sql_parse.cc:5115
#11 0x0000000000651ea4 in mysql_parse (thd=0x7f53b8dbd070, rawbuf=0x7f53a8311088 "ALTER TABLE `db`.`t2` COMMENT = 'UPDATED' /* QNO 23 CON_ID 6 */", length=63, parser_state=0x7f53d335a6a0) at /data/src/10.0/sql/sql_parse.cc:6576
#12 0x00000000006449a4 in dispatch_command (command=COM_QUERY, thd=0x7f53b8dbd070, packet=0x7f53b8dc3071 "ALTER TABLE `db`.`t2` COMMENT = 'UPDATED' /* QNO 23 CON_ID 6 */ ", packet_length=64) at /data/src/10.0/sql/sql_parse.cc:1309
#13 0x0000000000643c67 in do_command (thd=0x7f53b8dbd070) at /data/src/10.0/sql/sql_parse.cc:999
#14 0x0000000000761f70 in do_handle_one_connection (thd_arg=0x7f53b8dbd070) at /data/src/10.0/sql/sql_connect.cc:1378
#15 0x0000000000761ce2 in handle_one_connection (arg=0x7f53b8dbd070) at /data/src/10.0/sql/sql_connect.cc:1293
#16 0x00007f53d2ffe0a4 in start_thread (arg=0x7f53d335b700) at pthread_create.c:309
#17 0x00007f53d11b687d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

Thread 2 (Thread 0x7f53d3312700 (LWP 10016)):
#0  pthread_cond_timedwait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:238
#1  0x0000000000e247c4 in safe_cond_timedwait (cond=0x7f53a680e188, mp=0x7f53a68c0c08, abstime=0x7f53d3310940, file=0x104f820 "/data/src/10.0/include/mysql/psi/mysql_thread.h", line=1202) at /data/src/10.0/mysys/thr_mutex.c:547
#2  0x0000000000e211ca in inline_mysql_cond_timedwait (that=0x7f53a680e188, mutex=0x7f53a68c0c08, abstime=0x7f53d3310940, src_file=0x104f850 "/data/src/10.0/mysys/thr_lock.c", src_line=570) at /data/src/10.0/include/mysql/psi/mysql_thread.h:1202
#3  0x0000000000e217f1 in wait_for_lock (wait=0x7f53a68c0cd8, data=0x7f53a690f850, in_wait_list=0 '\000', lock_wait_timeout=31536000) at /data/src/10.0/mysys/thr_lock.c:570
#4  0x0000000000e2205b in thr_lock (data=0x7f53a690f850, owner=0x7f53b8dc9838, lock_wait_timeout=31536000) at /data/src/10.0/mysys/thr_lock.c:900
#5  0x0000000000e2291c in thr_multi_lock (data=0x7f53a681e898, count=2, owner=0x7f53b8dc9838, lock_wait_timeout=31536000) at /data/src/10.0/mysys/thr_lock.c:1179
#6  0x0000000000914e8e in mysql_lock_tables (thd=0x7f53b8dc8070, sql_lock=0x7f53a681e870, flags=0) at /data/src/10.0/sql/lock.cc:321
#7  0x0000000000914ce0 in mysql_lock_tables (thd=0x7f53b8dc8070, tables=0x7f53a6822f18, count=2, flags=0) at /data/src/10.0/sql/lock.cc:275
#8  0x00000000005ec013 in lock_tables (thd=0x7f53b8dc8070, tables=0x7f53a68221d8, count=2, flags=0) at /data/src/10.0/sql/sql_base.cc:5401
#9  0x00000000005ebad9 in open_and_lock_tables (thd=0x7f53b8dc8070, tables=0x7f53a68221d8, derived=true, flags=0, prelocking_strategy=0x7f53d3310c70) at /data/src/10.0/sql/sql_base.cc:5229
#10 0x00000000005dfe9d in open_and_lock_tables (thd=0x7f53b8dc8070, tables=0x7f53a68221d8, derived=true, flags=0) at /data/src/10.0/sql/sql_base.h:489
#11 0x0000000000649cd2 in mysql_execute_command (thd=0x7f53b8dc8070) at /data/src/10.0/sql/sql_parse.cc:3516
#12 0x0000000000651ea4 in mysql_parse (thd=0x7f53b8dc8070, rawbuf=0x7f53a6822088 "INSERT INTO `db`.`t2` SELECT * FROM `test`.`t1` /* QNO 22 CON_ID 7 */", length=69, parser_state=0x7f53d33116a0) at /data/src/10.0/sql/sql_parse.cc:6576
#13 0x00000000006449a4 in dispatch_command (command=COM_QUERY, thd=0x7f53b8dc8070, packet=0x7f53b8dd1071 " INSERT INTO `db`.`t2` SELECT * FROM `test`.`t1` /* QNO 22 CON_ID 7 */ ", packet_length=71) at /data/src/10.0/sql/sql_parse.cc:1309
#14 0x0000000000643c67 in do_command (thd=0x7f53b8dc8070) at /data/src/10.0/sql/sql_parse.cc:999
#15 0x0000000000761f70 in do_handle_one_connection (thd_arg=0x7f53b8dc8070) at /data/src/10.0/sql/sql_connect.cc:1378
#16 0x0000000000761ce2 in handle_one_connection (arg=0x7f53b8dc8070) at /data/src/10.0/sql/sql_connect.cc:1293
#17 0x00007f53d2ffe0a4 in start_thread (arg=0x7f53d3312700) at pthread_create.c:309
#18 0x00007f53d11b687d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

RQG grammar lock.yy

query_init:
    CREATE TABLE IF NOT EXISTS `test`.`t1` (`f1` INT, `pk` INT, `f2` INT, KEY(`f1`), PRIMARY KEY(`pk`)) ENGINE=MyISAM;
 
query:
	ddl | FLUSH TABLES ;
 
ddl:
	database_ddl |
	table_ddl | table_ddl | table_ddl  ;
 
database_ddl:
	create_database | create_database | create_database |
	drop_database ;
 
create_database:
	CREATE DATABASE IF NOT EXISTS `db`;
 
drop_database:
	DROP DATABASE IF EXISTS `db`;
 
table_ddl:
	create_table | create_table | create_table | create_table | create_table | create_table |
	drop_table | alter_table ;
 
create_table:
	CREATE TABLE IF NOT EXISTS `db`.`t2` LIKE `test`.`t1` ; INSERT INTO `db`.`t2` SELECT * FROM `test`.`t1` ;
    
drop_table:
	DROP TABLE IF EXISTS `db`.`t2` ;
 
alter_table:
	ALTER TABLE `db`.`t2` COMMENT = 'UPDATED' ;

RQG command line

perl ./runall-new.pl --grammar=lock.yy --skip-gendata --duration=300 --queries=100M --threads=2 \
--basedir=<your basedir> --vardir=<your vardir>

Use RQG from github.com:/elenst/rqg


Generated at Thu Feb 08 07:47:33 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.