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

Assertion `!table.n_waiting_or_granted_auto_inc_locks' failed in trx_t::drop_table

Details

    Description

      --source include/have_innodb.inc
      		 
       
      		 
      CREATE TABLE t1 (k INT) ENGINE=InnoDB;
      		 
      INSERT INTO t1 (k) VALUES (1);
      		 
      START TRANSACTION;
      		 
      INSERT INTO t1 (k) VALUES (2);
      		 
       
      		 
      --connect (con1,localhost,root,,test)
      		 
      SET innodb_lock_wait_timeout= 1;
      		 
      --error ER_LOCK_WAIT_TIMEOUT
      		 
      CREATE TABLE t2 (pk INT AUTO_INCREMENT PRIMARY KEY) ENGINE=InnoDB AS SELECT k FROM t1;
      		 
       
      		 
      # Cleanup
      		 
      --disconnect con1
      		 
      --connection default
      		 
      DROP TABLE t1;

      10.6 e5b9dc15

      		 
      mariadbd: /data/src/10.6/storage/innobase/dict/drop.cc:154: dberr_t trx_t::drop_table(const dict_table_t&): Assertion `!table.n_waiting_or_granted_auto_inc_locks' failed.
      		 
      210617  0:49:17 [ERROR] mysqld got signal 6 ;
      		 
       
      		 
      #7  0x00007fa452dd3f36 in __GI___assert_fail (assertion=0x5642bc01ebd0 "!table.n_waiting_or_granted_auto_inc_locks", file=0x5642bc01e8b8 "/data/src/10.6/storage/innobase/dict/drop.cc", line=154, function=0x5642bc01eb48 "dberr_t trx_t::drop_table(const dict_table_t&)") at assert.c:101
      		 
      #8  0x00005642bb9b3e46 in trx_t::drop_table (this=0x7fa44d2c7290, table=...) at /data/src/10.6/storage/innobase/dict/drop.cc:154
      		 
      #9  0x00005642bb65855d in ha_innobase::delete_table (this=0x7fa4140195f8, name=0x7fa447fb24f0 "./test/t2") at /data/src/10.6/storage/innobase/handler/ha_innodb.cc:13375
      		 
      #10 0x00005642bb1c08b6 in hton_drop_table (hton=0x5642bdd3a3f8, path=0x7fa447fb24f0 "./test/t2") at /data/src/10.6/sql/handler.cc:576
      		 
      #11 0x00005642bb1c6a15 in ha_delete_table (thd=0x7fa414000db8, hton=0x5642bdd3a3f8, path=0x7fa447fb24f0 "./test/t2", db=0x7fa4140142e0, alias=0x7fa4140142f0, generate_warning=false) at /data/src/10.6/sql/handler.cc:3071
      		 
      #12 0x00005642baf2e69e in quick_rm_table (thd=0x7fa414000db8, base=0x5642bdd3a3f8, db=0x7fa4140142e0, table_name=0x7fa4140142f0, flags=0, table_path=0x0) at /data/src/10.6/sql/sql_table.cc:1921
      		 
      #13 0x00005642bad8aec9 in drop_open_table (thd=0x7fa414000db8, table=0x7fa414026848, db_name=0x7fa4140142e0, table_name=0x7fa4140142f0) at /data/src/10.6/sql/sql_base.cc:1365
      		 
      #14 0x00005642badf6b07 in select_create::abort_result_set (this=0x7fa414016458) at /data/src/10.6/sql/sql_insert.cc:5168
      		 
      #15 0x00005642bae848df in handle_select (thd=0x7fa414000db8, lex=0x7fa414005068, result=0x7fa414016458, setup_tables_done_option=0) at /data/src/10.6/sql/sql_select.cc:562
      		 
      #16 0x00005642baf4c992 in Sql_cmd_create_table_like::execute (this=0x7fa414014268, thd=0x7fa414000db8) at /data/src/10.6/sql/sql_table.cc:11729
      		 
      #17 0x00005642bae4457e in mysql_execute_command (thd=0x7fa414000db8) at /data/src/10.6/sql/sql_parse.cc:5983
      		 
      #18 0x00005642bae4a724 in mysql_parse (thd=0x7fa414000db8, rawbuf=0x7fa414014160 "CREATE TABLE t2 (pk INT AUTO_INCREMENT PRIMARY KEY) ENGINE=InnoDB AS SELECT k FROM t1", length=85, parser_state=0x7fa447fb3480) at /data/src/10.6/sql/sql_parse.cc:8016
      		 
      #19 0x00005642bae36bae in dispatch_command (command=COM_QUERY, thd=0x7fa414000db8, packet=0x7fa41400b879 "CREATE TABLE t2 (pk INT AUTO_INCREMENT PRIMARY KEY) ENGINE=InnoDB AS SELECT k FROM t1", packet_length=85, blocking=true) at /data/src/10.6/sql/sql_parse.cc:1897
      		 
      #20 0x00005642bae35553 in do_command (thd=0x7fa414000db8, blocking=true) at /data/src/10.6/sql/sql_parse.cc:1406
      		 
      #21 0x00005642baff1d65 in do_handle_one_connection (connect=0x5642be291238, put_in_cache=true) at /data/src/10.6/sql/sql_connect.cc:1410
      		 
      #22 0x00005642baff1ac1 in handle_one_connection (arg=0x5642be291238) at /data/src/10.6/sql/sql_connect.cc:1312
      		 
      #23 0x00005642bb560fe9 in pfs_spawn_thread (arg=0x5642be2fdf68) at /data/src/10.6/storage/perfschema/pfs.cc:2201
      		 
      #24 0x00007fa4532eb609 in start_thread (arg=<optimized out>) at pthread_create.c:477
      		 
      #25 0x00007fa452ebf293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

      No obvious immediate problem on a non-debug build.
      The failure started happening in 10.6 after this commit:

      commit 1bd681c8b3c5213ce1f7976940a7dc38b48a0d39
      		 
      Author: Marko Mäkelä <marko.makela@mariadb.com>
      		 
      Date:   Wed Jun 9 17:02:55 2021 +0300
      		 
       
      		 
          MDEV-25506 (3 of 3): Do not delete .ibd files before commit
      		 
          
          This is a complete rewrite of DROP TABLE, also as part of other DDL,

      Attachments

        Activity

          Ascending order - Click to sort in descending order
          marko Marko Mäkelä added a comment -

          Thank you. I fixed this by removing the assertion.

          Remaining debug assertions will check that only this transaction is holding locks on the table, and that one of them is an exclusive lock.

          marko Marko Mäkelä added a comment - Thank you. I fixed this by removing the assertion. Remaining debug assertions will check that only this transaction is holding locks on the table, and that one of them is an exclusive lock.
          elenst Elena Stepanova added a comment -

          The same test case from the description still fails, now on a different assertion.

          10.6 c2ebe8147d

          		 
          mariadbd: /data/src/10.6-bug/storage/innobase/dict/drop.cc:165: dberr_t trx_t::drop_table(const dict_table_t&): Assertion `lock->type_mode == (LOCK_IX | 8U)' failed.
          		 
          210630  2:35:27 [ERROR] mysqld got signal 6 ;
          		 
           
          		 
          torage/innobase/dict/drop.cc", line=165, function=0x55699c692d20 "dberr_t trx_t::drop_table(const dict_table_t&)") at assert.c:101
          		 
          #8  0x000055699c022f2f in trx_t::drop_table (this=0x7fa3dca09280, table=...) at /data/src/10.6-bug/storage/innobase/dict/drop.cc:165
          		 
          #9  0x000055699bcc75c5 in ha_innobase::delete_table (this=0x7fa3a40195f8, name=0x7fa3d76fd4f0 "./test/t2") at /data/src/10.6-bug/storage/innobase/handler/ha_innodb.cc:13490
          		 
          #10 0x000055699b82e010 in hton_drop_table (hton=0x55699e269c48, path=0x7fa3d76fd4f0 "./test/t2") at /data/src/10.6-bug/sql/handler.cc:576
          		 
          #11 0x000055699b8343ae in ha_delete_table (thd=0x7fa3a4000db8, hton=0x55699e269c48, path=0x7fa3d76fd4f0 "./test/t2", db=0x7fa3a40142e0, alias=0x7fa3a40142f0, generate_warning=false) at /data/src/10.6-bug/sql/handler.cc:3086
          		 
          #12 0x000055699b59bb80 in quick_rm_table (thd=0x7fa3a4000db8, base=0x55699e269c48, db=0x7fa3a40142e0, table_name=0x7fa3a40142f0, flags=0, table_path=0x0) at /data/src/10.6-bug/sql/sql_table.cc:1921
          		 
          #13 0x000055699b3f7f2b in drop_open_table (thd=0x7fa3a4000db8, table=0x7fa3a4026848, db_name=0x7fa3a40142e0, table_name=0x7fa3a40142f0) at /data/src/10.6-bug/sql/sql_base.cc:1365
          		 
          #14 0x000055699b463b79 in select_create::abort_result_set (this=0x7fa3a4016458) at /data/src/10.6-bug/sql/sql_insert.cc:5168
          		 
          #15 0x000055699b4f1dff in handle_select (thd=0x7fa3a4000db8, lex=0x7fa3a4005068, result=0x7fa3a4016458, setup_tables_done_option=0) at /data/src/10.6-bug/sql/sql_select.cc:562
          		 
          #16 0x000055699b5b9f1c in Sql_cmd_create_table_like::execute (this=0x7fa3a4014268, thd=0x7fa3a4000db8) at /data/src/10.6-bug/sql/sql_table.cc:11751
          		 
          #17 0x000055699b4b1774 in mysql_execute_command (thd=0x7fa3a4000db8, is_called_from_prepared_stmt=false) at /data/src/10.6-bug/sql/sql_parse.cc:5995
          		 
          #18 0x000055699b4b791f in mysql_parse (thd=0x7fa3a4000db8, rawbuf=0x7fa3a4014160 "CREATE TABLE t2 (pk INT AUTO_INCREMENT PRIMARY KEY) ENGINE=InnoDB AS SELECT k FROM t1", length=85, parser_state=0x7fa3d76fe480) at /data/src/10.6-bug/sql/sql_parse.cc:8028
          		 
          #19 0x000055699b4a3d59 in dispatch_command (command=COM_QUERY, thd=0x7fa3a4000db8, packet=0x7fa3a400b879 "CREATE TABLE t2 (pk INT AUTO_INCREMENT PRIMARY KEY) ENGINE=InnoDB AS SELECT k FROM t1", packet_length=85, blocking=true) at /data/src/10.6-bug/sql/sql_parse.cc:1898
          		 
          #20 0x000055699b4a26f5 in do_command (thd=0x7fa3a4000db8, blocking=true) at /data/src/10.6-bug/sql/sql_parse.cc:1406
          		 
          #21 0x000055699b65f3cb in do_handle_one_connection (connect=0x55699e80c4f8, put_in_cache=true) at /data/src/10.6-bug/sql/sql_connect.cc:1410
          		 
          #22 0x000055699b65f127 in handle_one_connection (arg=0x55699e80c4f8) at /data/src/10.6-bug/sql/sql_connect.cc:1312
          		 
          #23 0x000055699bbcf313 in pfs_spawn_thread (arg=0x55699e80c5d8) at /data/src/10.6-bug/storage/perfschema/pfs.cc:2201
          		 
          #24 0x00007fa3e2a2e609 in start_thread (arg=<optimized out>) at pthread_create.c:477
          		 
          #25 0x00007fa3e2601293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

          On the next fixing attempt, whether it's removing another assertion or anything else, please add the test case to the regression suite.

          elenst Elena Stepanova added a comment - The same test case from the description still fails, now on a different assertion. 10.6 c2ebe8147d mariadbd: /data/src/10.6-bug/storage/innobase/dict/drop.cc:165: dberr_t trx_t::drop_table(const dict_table_t&): Assertion `lock->type_mode == (LOCK_IX | 8U)' failed. 210630 2:35:27 [ERROR] mysqld got signal 6 ;   torage/innobase/dict/drop.cc", line=165, function=0x55699c692d20 "dberr_t trx_t::drop_table(const dict_table_t&)") at assert.c:101 #8 0x000055699c022f2f in trx_t::drop_table (this=0x7fa3dca09280, table=...) at /data/src/10.6-bug/storage/innobase/dict/drop.cc:165 #9 0x000055699bcc75c5 in ha_innobase::delete_table (this=0x7fa3a40195f8, name=0x7fa3d76fd4f0 "./test/t2") at /data/src/10.6-bug/storage/innobase/handler/ha_innodb.cc:13490 #10 0x000055699b82e010 in hton_drop_table (hton=0x55699e269c48, path=0x7fa3d76fd4f0 "./test/t2") at /data/src/10.6-bug/sql/handler.cc:576 #11 0x000055699b8343ae in ha_delete_table (thd=0x7fa3a4000db8, hton=0x55699e269c48, path=0x7fa3d76fd4f0 "./test/t2", db=0x7fa3a40142e0, alias=0x7fa3a40142f0, generate_warning=false) at /data/src/10.6-bug/sql/handler.cc:3086 #12 0x000055699b59bb80 in quick_rm_table (thd=0x7fa3a4000db8, base=0x55699e269c48, db=0x7fa3a40142e0, table_name=0x7fa3a40142f0, flags=0, table_path=0x0) at /data/src/10.6-bug/sql/sql_table.cc:1921 #13 0x000055699b3f7f2b in drop_open_table (thd=0x7fa3a4000db8, table=0x7fa3a4026848, db_name=0x7fa3a40142e0, table_name=0x7fa3a40142f0) at /data/src/10.6-bug/sql/sql_base.cc:1365 #14 0x000055699b463b79 in select_create::abort_result_set (this=0x7fa3a4016458) at /data/src/10.6-bug/sql/sql_insert.cc:5168 #15 0x000055699b4f1dff in handle_select (thd=0x7fa3a4000db8, lex=0x7fa3a4005068, result=0x7fa3a4016458, setup_tables_done_option=0) at /data/src/10.6-bug/sql/sql_select.cc:562 #16 0x000055699b5b9f1c in Sql_cmd_create_table_like::execute (this=0x7fa3a4014268, thd=0x7fa3a4000db8) at /data/src/10.6-bug/sql/sql_table.cc:11751 #17 0x000055699b4b1774 in mysql_execute_command (thd=0x7fa3a4000db8, is_called_from_prepared_stmt=false) at /data/src/10.6-bug/sql/sql_parse.cc:5995 #18 0x000055699b4b791f in mysql_parse (thd=0x7fa3a4000db8, rawbuf=0x7fa3a4014160 "CREATE TABLE t2 (pk INT AUTO_INCREMENT PRIMARY KEY) ENGINE=InnoDB AS SELECT k FROM t1", length=85, parser_state=0x7fa3d76fe480) at /data/src/10.6-bug/sql/sql_parse.cc:8028 #19 0x000055699b4a3d59 in dispatch_command (command=COM_QUERY, thd=0x7fa3a4000db8, packet=0x7fa3a400b879 "CREATE TABLE t2 (pk INT AUTO_INCREMENT PRIMARY KEY) ENGINE=InnoDB AS SELECT k FROM t1", packet_length=85, blocking=true) at /data/src/10.6-bug/sql/sql_parse.cc:1898 #20 0x000055699b4a26f5 in do_command (thd=0x7fa3a4000db8, blocking=true) at /data/src/10.6-bug/sql/sql_parse.cc:1406 #21 0x000055699b65f3cb in do_handle_one_connection (connect=0x55699e80c4f8, put_in_cache=true) at /data/src/10.6-bug/sql/sql_connect.cc:1410 #22 0x000055699b65f127 in handle_one_connection (arg=0x55699e80c4f8) at /data/src/10.6-bug/sql/sql_connect.cc:1312 #23 0x000055699bbcf313 in pfs_spawn_thread (arg=0x55699e80c5d8) at /data/src/10.6-bug/storage/perfschema/pfs.cc:2201 #24 0x00007fa3e2a2e609 in start_thread (arg=<optimized out>) at pthread_create.c:477 #25 0x00007fa3e2601293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95 On the next fixing attempt, whether it's removing another assertion or anything else, please add the test case to the regression suite.
          marko Marko Mäkelä added a comment -

          Sorry, it indeed looks like I must have forgotten to rerun the test case after removing the assertion. The remaining failing assertion must be relaxed as well, because the current transaction may hold an auto-increment lock on the table in addition to holding an exclusive lock.

          Initially I did not want to add the test case to the regression suite, because it includes a lock wait timeout and thus increases the regression test run time by a whole second (since in MDEV-24671 we did not expose the subsecond precision of pthread_cond_timedwait() to the user). I have now added the test case to the regression test suite.

          marko Marko Mäkelä added a comment - Sorry, it indeed looks like I must have forgotten to rerun the test case after removing the assertion. The remaining failing assertion must be relaxed as well, because the current transaction may hold an auto-increment lock on the table in addition to holding an exclusive lock. Initially I did not want to add the test case to the regression suite, because it includes a lock wait timeout and thus increases the regression test run time by a whole second (since in MDEV-24671 we did not expose the subsecond precision of pthread_cond_timedwait() to the user). I have now added the test case to the regression test suite.
          elenst Elena Stepanova added a comment -

          For the regression suite you can use innodb_lock_wait_timeout= 0 instead.

          elenst Elena Stepanova added a comment - For the regression suite you can use innodb_lock_wait_timeout= 0 instead.
          marko Marko Mäkelä added a comment -

          You are right; I wrongly remembered that the value 0 would be infinite, while in fact it is an immediate timeout. Values between 100,000,000 and 1,073,741,824 would be an infinite timeout. On systems with 32-bit time_t, the 99,999,999-second timeout (3 years, 62 days and 9 hours) would become an immediate timeout if the wake-up time would be after some time in the year 2038.

          marko Marko Mäkelä added a comment - You are right; I wrongly remembered that the value 0 would be infinite, while in fact it is an immediate timeout. Values between 100,000,000 and 1,073,741,824 would be an infinite timeout. On systems with 32-bit time_t , the 99,999,999-second timeout (3 years, 62 days and 9 hours) would become an immediate timeout if the wake-up time would be after some time in the year 2038.

          People

            marko Marko Mäkelä
            elenst Elena Stepanova
            Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved:

              Git Integration

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