Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-11132

Extra locking upon concurrent DDL/DML

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Open (View Workflow)
    • Priority: Major
    • Resolution: Unresolved
    • Affects Version/s: 10.0, 10.1, 10.2
    • Fix Version/s: 10.2
    • Component/s: Locking
    • 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

        Attachments

          Activity

            People

            Assignee:
            wlad Vladislav Vaintroub
            Reporter:
            elenst Elena Stepanova
            Votes:
            1 Vote for this issue
            Watchers:
            4 Start watching this issue

              Dates

              Created:
              Updated:

                Git Integration

                Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.