[MDEV-25500] Assertion `table_share->tmp_table != NO_TMP_TABLE || m_lock_type != 2' failed in uint handler::get_dup_key(int) Created: 2021-04-23  Updated: 2022-11-08  Resolved: 2022-11-08

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB
Affects Version/s: 10.2, 10.3, 10.4, 10.5, 10.6
Fix Version/s: 10.6.2

Type: Bug Priority: Major
Reporter: Ramesh Sivaraman Assignee: Marko Mäkelä
Resolution: Won't Fix Votes: 0
Labels: None

Issue Links:
Blocks
is blocked by MDEV-21175 Remove dict_table_t::n_foreign_key_ch... Closed
Relates
relates to MDEV-25696 Assertion `table_share->tmp_table != ... Confirmed

 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)

 Comments   
Comment by Sergei Golubchik [ 2021-04-26 ]

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

Comment by Ramesh Sivaraman [ 2021-04-26 ]

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

Comment by Roel Van de Paar [ 2021-04-26 ]

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

Comment by Sergei Golubchik [ 2021-04-28 ]

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

Comment by Marko Mäkelä [ 2021-04-29 ]

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,

Comment by Marko Mäkelä [ 2021-04-29 ]

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.

Comment by Marko Mäkelä [ 2021-05-17 ]

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.

Comment by Marko Mäkelä [ 2022-11-08 ]

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.

Generated at Thu Feb 08 09:38:10 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.