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

Assertion `table_share->tmp_table != NO_TMP_TABLE || m_lock_type != 2' failed in uint handler::get_dup_key(int)

Details

    • Bug
    • Status: Closed (View Workflow)
    • Major
    • Resolution: Won't Fix
    • 10.2(EOL), 10.3(EOL), 10.4(EOL), 10.5, 10.6
    • 10.6.2
    • None

    Description

      SET debug_dbug='+d,row_drop_table_add_to_background';
      CREATE TABLE t1 (a INT NOT NULL) ENGINE=InnoDB;
      ALTER TABLE t1 ADD c2 TEXT NOT NULL;
      DROP TABLE t1;
      

      Leads to:

      10.2.38 (Debug)

      mysqld: /test/10.2_dbg/sql/handler.cc:3989: uint handler::get_dup_key(int): Assertion `table_share->tmp_table != NO_TMP_TABLE || m_lock_type != 2' failed.
      

      10.2.38 (Debug)

      Core was generated by `/test/MD160321-mariadb-10.2.38-linux-x86_64-dbg/bin/mysqld --no-defaults --core'.
      Program terminated with signal SIGABRT, Aborted.
      #0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6)
          at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
      [Current thread is 1 (Thread 0x1516dc9dc700 (LWP 3902701))]
      (gdb) bt
      #0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
      #1  0x000055d689c16f9a in my_write_core (sig=sig@entry=6) at /test/10.2_dbg/mysys/stacktrace.c:382
      #2  0x000055d6894fd043 in handle_fatal_signal (sig=6) at /test/10.2_dbg/sql/signal_handler.cc:343
      #3  <signal handler called>
      #4  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
      #5  0x00001516f7a64859 in __GI_abort () at abort.c:79
      #6  0x00001516f7a64729 in __assert_fail_base (fmt=0x1516f7bfa588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x55d689d800c0 "table_share->tmp_table != NO_TMP_TABLE || m_lock_type != 2", file=0x55d689d81169 "/test/10.2_dbg/sql/handler.cc", line=3989, function=<optimized out>) at assert.c:92
      #7  0x00001516f7a75f36 in __GI___assert_fail (assertion=assertion@entry=0x55d689d800c0 "table_share->tmp_table != NO_TMP_TABLE || m_lock_type != 2", file=file@entry=0x55d689d81169 "/test/10.2_dbg/sql/handler.cc", line=line@entry=3989, function=function@entry=0x55d689d80518 "uint handler::get_dup_key(int)") at assert.c:101
      #8  0x000055d68950622e in handler::get_dup_key (this=this@entry=0x151698011aa0, error=error@entry=121) at /test/10.2_dbg/sql/handler.cc:3991
      #9  0x000055d6895064fe in handler::print_error (this=0x151698011aa0, error=121, errflag=0) at /test/10.2_dbg/sql/handler.cc:3575
      #10 0x000055d689507d4f in ha_delete_table (thd=thd@entry=0x151698000d90, table_type=<optimized out>, path=path@entry=0x1516dc9d9b50 "./test/t1", db=<optimized out>, db@entry=0x151698011870 "test", alias=<optimized out>, generate_warning=generate_warning@entry=true) at /test/10.2_dbg/sql/handler.cc:2464
      #11 0x000055d689397d4c in mysql_rm_table_no_locks (thd=thd@entry=0x151698000d90, tables=tables@entry=0x151698011258, if_exists=if_exists@entry=false, drop_temporary=drop_temporary@entry=false, drop_view=drop_view@entry=false, dont_log_query=dont_log_query@entry=false, dont_free_locks=false) at /test/10.2_dbg/sql/sql_table.cc:2447
      #12 0x000055d689398e3a in mysql_rm_table (thd=thd@entry=0x151698000d90, tables=tables@entry=0x151698011258, if_exists=<optimized out>, drop_temporary=<optimized out>) at /test/10.2_dbg/sql/sql_table.cc:2089
      #13 0x000055d6892fa2b9 in mysql_execute_command (thd=thd@entry=0x151698000d90) at /test/10.2_dbg/sql/structs.h:530
      #14 0x000055d6892ffe33 in mysql_parse (thd=thd@entry=0x151698000d90, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x1516dc9db550, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /test/10.2_dbg/sql/sql_parse.cc:7790
      #15 0x000055d689302933 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x151698000d90, packet=packet@entry=0x1516980195d1 "DROP TABLE t1", packet_length=packet_length@entry=13, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /test/10.2_dbg/sql/sql_class.h:1109
      #16 0x000055d68930573c in do_command (thd=0x151698000d90) at /test/10.2_dbg/sql/sql_parse.cc:1381
      #17 0x000055d689408bcc in do_handle_one_connection (connect=connect@entry=0x55d68bbe02e0) at /test/10.2_dbg/sql/sql_connect.cc:1336
      #18 0x000055d689408df7 in handle_one_connection (arg=0x55d68bbe02e0) at /test/10.2_dbg/sql/sql_connect.cc:1241
      #19 0x00001516f7f6a609 in start_thread (arg=<optimized out>) at pthread_create.c:477
      #20 0x00001516f7b61293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
      

      Bug confirmed present in:
      MariaDB: 10.2.38 (dbg)

      Bug (or feature/syntax) confirmed not present in:
      MariaDB: 10.3.29 (dbg), 10.4.19 (dbg), 10.5.10 (dbg), 10.6.0 (dbg)

      Attachments

        Issue Links

          Activity

            ramesh, is it a bug? may be it's supposed to crash. Please, clarify.

            serg Sergei Golubchik added a comment - ramesh , is it a bug? may be it's supposed to crash. Please, clarify.

            serg I think it is a bug as the crash is only happening when we execute DROP TABLE immediately after ALTER TABLE statement. When we add 1 sec delay after ALTER TABLE statement the crash is not happening.

            innodb.drop_table_background MTR test also crashing if we add ALTER TABLE statement in the testcase.

            $ grep -A6 add suite/innodb/t/drop_table_background.test
            SET DEBUG_DBUG='+d,row_drop_table_add_to_background';
            CREATE TABLE t1 (a INT NOT NULL) ENGINE=InnoDB;
            ALTER TABLE t1 ADD c2 TEXT NOT NULL;
            DROP TABLE t1;
             
            --disable_query_log
            

            Executed DROP TABLE statement after ALTER TABLE statement without any delay.

            10.2.38-dbg>SET debug_dbug='+d,row_drop_table_add_to_background';
            Query OK, 0 rows affected (0.00 sec)
             
            10.2.38-dbg>CREATE TABLE t1 (a INT NOT NULL) ENGINE=InnoDB;
            Query OK, 0 rows affected (0.02 sec)
             
            10.2.38-dbg>ALTER TABLE t1 ADD c2 TEXT NOT NULL;
            Query OK, 0 rows affected (0.03 sec)
            Records: 0  Duplicates: 0  Warnings: 0
             
            10.2.38-dbg>DROP TABLE t1;
             
            ERROR 2013 (HY000): Lost connection to MySQL server during query
            10.2.38-dbg>
             
            General Log:
             
            210426 16:30:58     9 Query     SET debug_dbug='+d,row_drop_table_add_to_background'
                                9 Query     CREATE TABLE t1 (a INT NOT NULL) ENGINE=InnoDB
                                9 Query     ALTER TABLE t1 ADD c2 TEXT NOT NULL
                                9 Query     DROP TABLE t1
            

            Executed DROP TABLE statement after ALTER TABLE statement with 1sec delay.

            10.2.38-dbg>SET debug_dbug='+d,row_drop_table_add_to_background';
            Query OK, 0 rows affected (0.00 sec)
             
            10.2.38-dbg>CREATE TABLE t1 (a INT NOT NULL) ENGINE=InnoDB;
            Query OK, 0 rows affected (0.02 sec)
             
            10.2.38-dbg>ALTER TABLE t1 ADD c2 TEXT NOT NULL;
            Query OK, 0 rows affected (0.02 sec)
            Records: 0  Duplicates: 0  Warnings: 0
             
            10.2.38-dbg>SELECT SLEEP(1);
             
            +----------+
            | SLEEP(1) |
            +----------+
            |        0 |
            +----------+
            1 row in set (1.00 sec)
             
            10.2.38-dbg>DROP TABLE t1;
            Query OK, 0 rows affected (0.01 sec)
             
            10.2.38-dbg>
             
            General Log:
             
            210426 16:32:02     9 Query     SET debug_dbug='+d,row_drop_table_add_to_background'
                                9 Query     CREATE TABLE t1 (a INT NOT NULL) ENGINE=InnoDB
                                9 Query     ALTER TABLE t1 ADD c2 TEXT NOT NULL
                                9 Query     SELECT SLEEP(1)
            210426 16:32:03     9 Query     DROP TABLE t1
            

            ramesh Ramesh Sivaraman added a comment - serg I think it is a bug as the crash is only happening when we execute DROP TABLE immediately after ALTER TABLE statement. When we add 1 sec delay after ALTER TABLE statement the crash is not happening. innodb.drop_table_background MTR test also crashing if we add ALTER TABLE statement in the testcase. $ grep -A6 add suite/innodb/t/drop_table_background.test SET DEBUG_DBUG='+d,row_drop_table_add_to_background'; CREATE TABLE t1 (a INT NOT NULL) ENGINE=InnoDB; ALTER TABLE t1 ADD c2 TEXT NOT NULL; DROP TABLE t1;   --disable_query_log Executed DROP TABLE statement after ALTER TABLE statement without any delay. 10.2.38-dbg>SET debug_dbug='+d,row_drop_table_add_to_background'; Query OK, 0 rows affected (0.00 sec)   10.2.38-dbg>CREATE TABLE t1 (a INT NOT NULL) ENGINE=InnoDB; Query OK, 0 rows affected (0.02 sec)   10.2.38-dbg>ALTER TABLE t1 ADD c2 TEXT NOT NULL; Query OK, 0 rows affected (0.03 sec) Records: 0 Duplicates: 0 Warnings: 0   10.2.38-dbg>DROP TABLE t1;   ERROR 2013 (HY000): Lost connection to MySQL server during query 10.2.38-dbg>   General Log:   210426 16:30:58 9 Query SET debug_dbug='+d,row_drop_table_add_to_background' 9 Query CREATE TABLE t1 (a INT NOT NULL) ENGINE=InnoDB 9 Query ALTER TABLE t1 ADD c2 TEXT NOT NULL 9 Query DROP TABLE t1 Executed DROP TABLE statement after ALTER TABLE statement with 1sec delay. 10.2.38-dbg>SET debug_dbug='+d,row_drop_table_add_to_background'; Query OK, 0 rows affected (0.00 sec)   10.2.38-dbg>CREATE TABLE t1 (a INT NOT NULL) ENGINE=InnoDB; Query OK, 0 rows affected (0.02 sec)   10.2.38-dbg>ALTER TABLE t1 ADD c2 TEXT NOT NULL; Query OK, 0 rows affected (0.02 sec) Records: 0 Duplicates: 0 Warnings: 0   10.2.38-dbg>SELECT SLEEP(1);   +----------+ | SLEEP(1) | +----------+ | 0 | +----------+ 1 row in set (1.00 sec)   10.2.38-dbg>DROP TABLE t1; Query OK, 0 rows affected (0.01 sec)   10.2.38-dbg>   General Log:   210426 16:32:02 9 Query SET debug_dbug='+d,row_drop_table_add_to_background' 9 Query CREATE TABLE t1 (a INT NOT NULL) ENGINE=InnoDB 9 Query ALTER TABLE t1 ADD c2 TEXT NOT NULL 9 Query SELECT SLEEP(1) 210426 16:32:03 9 Query DROP TABLE t1

            The issue is also only present in 10.2 so something changed in 10.3 and onwards.

            Roel Roel Van de Paar added a comment - The issue is also only present in 10.2 so something changed in 10.3 and onwards.

            What does this row_drop_table_add_to_background do? Could a crash be an expected effect of it?

            serg Sergei Golubchik added a comment - What does this row_drop_table_add_to_background do? Could a crash be an expected effect of it?

            I can repeat the crash on 10.6 with a more generic test case that does not depend on MDEV-11369:

            --source include/have_innodb.inc
            SET debug_dbug='+d,row_drop_table_add_to_background';
            CREATE TABLE t1 (a INT NOT NULL) ENGINE=InnoDB;
            ALTER TABLE t1 FORCE;
            DROP TABLE t1;
            

            The duplicate table name was created in ctx->tmp_name by dict_mem_create_temporary_tablename() in ha_innobase::commit_inplace_alter_table() for discarding the old copy of t1. We used the wrong table identifier when constructing the name. The purpose of that identifier is to ultimately discard the old copy of the table. The following patch makes the test case pass:

            diff --git a/storage/innobase/handler/handler0alter.cc b/storage/innobase/handler/handler0alter.cc
            index 3ac4f4fe4c1..1a58ca7ea36 100644
            --- a/storage/innobase/handler/handler0alter.cc
            +++ b/storage/innobase/handler/handler0alter.cc
            @@ -8520,7 +8520,7 @@ ha_innobase::commit_inplace_alter_table(
             		} else if (ctx->need_rebuild()) {
             			ctx->tmp_name = dict_mem_create_temporary_tablename(
             				ctx->heap, ctx->new_table->name.m_name,
            -				ctx->new_table->id);
            +				ctx->old_table->id);
             
             			fail = commit_try_rebuild(
             				ha_alter_info, ctx, altered_table, table,
            

            marko Marko Mäkelä added a comment - I can repeat the crash on 10.6 with a more generic test case that does not depend on MDEV-11369 : --source include/have_innodb.inc SET debug_dbug= '+d,row_drop_table_add_to_background' ; CREATE TABLE t1 (a INT NOT NULL ) ENGINE=InnoDB; ALTER TABLE t1 FORCE ; DROP TABLE t1; The duplicate table name was created in ctx->tmp_name by dict_mem_create_temporary_tablename() in ha_innobase::commit_inplace_alter_table() for discarding the old copy of t1 . We used the wrong table identifier when constructing the name. The purpose of that identifier is to ultimately discard the old copy of the table. The following patch makes the test case pass: diff --git a/storage/innobase/handler/handler0alter.cc b/storage/innobase/handler/handler0alter.cc index 3ac4f4fe4c1..1a58ca7ea36 100644 --- a/storage/innobase/handler/handler0alter.cc +++ b/storage/innobase/handler/handler0alter.cc @@ -8520,7 +8520,7 @@ ha_innobase::commit_inplace_alter_table( } else if (ctx->need_rebuild()) { ctx->tmp_name = dict_mem_create_temporary_tablename( ctx->heap, ctx->new_table->name.m_name, - ctx->new_table->id); + ctx->old_table->id); fail = commit_try_rebuild( ha_alter_info, ctx, altered_table, table,

            My code change would cause a failure of an existing regression test:

            CURRENT_TEST: innodb.rename_table_debug
            mysqltest: At line 38: query 'SELECT * FROM t1' failed: 1286: Unknown storage engine 'InnoDB'
            

            The server error log contains the following:

            2021-04-29 13:09:08 140098167039936 [Note] InnoDB: Starting crash recovery from checkpoint LSN=3701637
            2021-04-29 13:09:08 140098167039936 [Note] InnoDB: Ignoring data file './test/t2.ibd' with space ID 69. Another data file called ./test/t1.ibd exists with the same space ID.
            2021-04-29 13:09:08 140098167039936 [ERROR] InnoDB: Cannot rename './test/t1.ibd' to './test/t2.ibd' for space ID 69 because the target file exists. Remove the target file and try again.
            2021-04-29 13:09:08 140098167039936 [ERROR] InnoDB:  Cannot replay file rename. Remove either file and try again.
            2021-04-29 13:09:08 140098167039936 [ERROR] InnoDB: Plugin initialization aborted at srv0start.cc[2209] with error Generic error
            2021-04-29 13:09:09 140098167039936 [Note] InnoDB: Starting shutdown...
            

            The background DROP TABLE queue would be removed in MDEV-21175. Until then, I think that failures like this are possible (but unlikely) even without setting the debug parameter.

            A more complex scenario would involve a FOREIGN KEY check that is being performed on the table near the time the ALTER TABLE is finishing. In that case, the old copy of the table would be renamed, to be added to the background DROP TABLE queue. If a DROP TABLE is being executed on the newly rebuilt table such that also for that table, another FOREIGN KEY check is in progress, and the queue had not been emptied yet, then we would have a duplicate name for the table.

            marko Marko Mäkelä added a comment - My code change would cause a failure of an existing regression test: CURRENT_TEST: innodb.rename_table_debug mysqltest: At line 38: query 'SELECT * FROM t1' failed: 1286: Unknown storage engine 'InnoDB' The server error log contains the following: 2021-04-29 13:09:08 140098167039936 [Note] InnoDB: Starting crash recovery from checkpoint LSN=3701637 2021-04-29 13:09:08 140098167039936 [Note] InnoDB: Ignoring data file './test/t2.ibd' with space ID 69. Another data file called ./test/t1.ibd exists with the same space ID. 2021-04-29 13:09:08 140098167039936 [ERROR] InnoDB: Cannot rename './test/t1.ibd' to './test/t2.ibd' for space ID 69 because the target file exists. Remove the target file and try again. 2021-04-29 13:09:08 140098167039936 [ERROR] InnoDB: Cannot replay file rename. Remove either file and try again. 2021-04-29 13:09:08 140098167039936 [ERROR] InnoDB: Plugin initialization aborted at srv0start.cc[2209] with error Generic error 2021-04-29 13:09:09 140098167039936 [Note] InnoDB: Starting shutdown... The background DROP TABLE queue would be removed in MDEV-21175 . Until then, I think that failures like this are possible (but unlikely) even without setting the debug parameter. A more complex scenario would involve a FOREIGN KEY check that is being performed on the table near the time the ALTER TABLE is finishing. In that case, the old copy of the table would be renamed, to be added to the background DROP TABLE queue. If a DROP TABLE is being executed on the newly rebuilt table such that also for that table, another FOREIGN KEY check is in progress, and the queue had not been emptied yet, then we would have a duplicate name for the table.

            For the originally reported failure, a possible solution could be to allocate a different type of a temporary table name in ha_innobase::commit_inplace_alter_table(). That name could consist of both the current table ID as well as the related table ID. In that way, a clash between the two to-be-dropped table names would not be possible.

            marko Marko Mäkelä added a comment - For the originally reported failure, a possible solution could be to allocate a different type of a temporary table name in ha_innobase::commit_inplace_alter_table() . That name could consist of both the current table ID as well as the related table ID. In that way, a clash between the two to-be-dropped table names would not be possible.

            This was fixed in MDEV-25506 in MariaDB Server 10.6.2. I do not think that it is feasible to fix this in older releases.

            marko Marko Mäkelä added a comment - This was fixed in MDEV-25506 in MariaDB Server 10.6.2. I do not think that it is feasible to fix this in older releases.

            People

              marko Marko Mäkelä
              ramesh Ramesh Sivaraman
              Votes:
              0 Vote for this issue
              Watchers:
              5 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.