[MDEV-20460] Assertion `inited==INDEX' failed in handler::ha_index_end upon concurrent SELECT and table re-creation Created: 2019-08-31  Updated: 2023-11-28

Status: Confirmed
Project: MariaDB Server
Component/s: Server
Affects Version/s: 10.1, 10.2, 10.3, 10.4, 10.5, 10.6, 10.7, 10.8, 10.9, 10.10, 10.11, 11.0
Fix Version/s: 10.4, 10.5, 10.6, 10.11

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Oleksandr Byelkin
Resolution: Unresolved Votes: 0
Labels: None


 Description   

Note: It is a concurrent test case, run with --repeat=N. Currently it always fails for me within 3 attempts, but it can vary on different machines and builds.

--source include/have_innodb.inc
 
 
 
CREATE TABLE t1 (a INT) ENGINE=InnoDB;
 
CREATE TABLE t2 (b INT) ENGINE=InnoDB;
 
START TRANSACTION;
 
SELECT * FROM t2;
 
--connect (con1,localhost,root,,test)
 
--send
 
CREATE OR REPLACE TABLE t1 (a INT, KEY(a)) ENGINE=InnoDB;
 
--connection default
 
--error 0,ER_TABLE_DEF_CHANGED
 
SELECT MAX(a) FROM t1;
 
 
 
# Cleanup
 
COMMIT;
 
--connection con1
 
--reap
 
--disconnect con1
 
--connection default
 
DROP TABLE t1, t2;

10.1 de0f93fb

 
mysqld: /data/src/10.1/sql/handler.h:2786: int handler::ha_index_end(): Assertion `inited==INDEX' failed.
 
190831 12:48:47 [ERROR] mysqld got signal 6 ;
 
 
 
#7  0x00007f450dd01f12 in __GI___assert_fail (assertion=0x555914f29d04 "inited==INDEX", file=0x555914f29cbf "/data/src/10.1/sql/handler.h", line=2786, function=0x555914f2cfd0 <handler::ha_index_end()::__PRETTY_FUNCTION__> "int handler::ha_index_end()") at assert.c:101
 
#8  0x0000555914528a06 in handler::ha_index_end (this=0x7f44f7caf888) at /data/src/10.1/sql/handler.h:2786
 
#9  0x000055591491ede5 in opt_sum_query (thd=0x7f4504761070, tables=..., all_fields=..., conds=0x0) at /data/src/10.1/sql/opt_sum.cc:412
 
#10 0x00005559145d7405 in JOIN::optimize_inner (this=0x7f44f7c45ad0) at /data/src/10.1/sql/sql_select.cc:1321
 
#11 0x00005559145d6556 in JOIN::optimize (this=0x7f44f7c45ad0) at /data/src/10.1/sql/sql_select.cc:1059
 
#12 0x00005559145deebb in mysql_select (thd=0x7f4504761070, rref_pointer_array=0x7f4504765570, tables=0x7f44f7c453d8, wild_num=0, fields=..., conds=0x0, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2148797184, result=0x7f44f7c45ab0, unit=0x7f4504764bc0, select_lex=0x7f45047652c8) at /data/src/10.1/sql/sql_select.cc:3487
 
#13 0x00005559145d4622 in handle_select (thd=0x7f4504761070, lex=0x7f4504764af8, result=0x7f44f7c45ab0, setup_tables_done_option=0) at /data/src/10.1/sql/sql_select.cc:377
 
#14 0x00005559145a3827 in execute_sqlcom_select (thd=0x7f4504761070, all_tables=0x7f44f7c453d8) at /data/src/10.1/sql/sql_parse.cc:5691
 
#15 0x000055591459a63f in mysql_execute_command (thd=0x7f4504761070) at /data/src/10.1/sql/sql_parse.cc:3038
 
#16 0x00005559145a749f in mysql_parse (thd=0x7f4504761070, rawbuf=0x7f44f7c45088 "SELECT MAX(a) FROM t1", length=21, parser_state=0x7f450f71a1e0) at /data/src/10.1/sql/sql_parse.cc:7209
 
#17 0x0000555914596651 in dispatch_command (command=COM_QUERY, thd=0x7f4504761070, packet=0x7f450469b071 "SELECT MAX(a) FROM t1", packet_length=21) at /data/src/10.1/sql/sql_parse.cc:1499
 
#18 0x000055591459540f in do_command (thd=0x7f4504761070) at /data/src/10.1/sql/sql_parse.cc:1131
 
#19 0x00005559146d2591 in do_handle_one_connection (thd_arg=0x7f4504761070) at /data/src/10.1/sql/sql_connect.cc:1331
 
#20 0x00005559146d22c2 in handle_one_connection (arg=0x7f4504761070) at /data/src/10.1/sql/sql_connect.cc:1242
 
#21 0x0000555914b07290 in pfs_spawn_thread (arg=0x7f4508bb03f0) at /data/src/10.1/storage/perfschema/pfs.cc:1861
 
#22 0x00007f450f3a84a4 in start_thread (arg=0x7f450f71b700) at pthread_create.c:456
 
#23 0x00007f450ddbed0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97

Non-debug build produces

mysqltest: At line 12: query 'SELECT MAX(a) FROM t1' failed: 1412: Table definition has changed, please retry transaction

which might be expected (it is masked in the test case above, so to see it, you need to remove the --error line.

 Comments   
Comment by Roel Van de Paar [ 2021-04-23 ]

Ran into this one also from a different angle:

SET @@GLOBAL.innodb_trx_rseg_n_slots_debug=1,@@SESSION.pseudo_slave_mode=ON;
 
CREATE TABLE t1 (a INT KEY) ENGINE=InnoDB;
 
CREATE TABLE t2 (a INT KEY) ENGINE=InnoDB;
 
XA START 'a';
 
INSERT INTO t2 VALUES (0);
 
XA END 'a';
 
XA PREPARE 'a';
 
DROP TABLE t1;   # ERROR 1637 (HY000): Too many active concurrent transactions
 
SELECT * FROM t1;  # ERROR 1030 (HY000): Got error 1877 "Unknown error 1877" from storage engine InnoDB
 
SELECT a FROM t1 WHERE a=(SELECT MAX(a) FROM t1);  # Crash

Leads to:

10.6.0 a3e3225cd3b816d47621e749e21a71b6a864a96a (Debug)

 
mysqld: /test/10.6_dbg/sql/handler.h:3410: int handler::ha_index_end(): Assertion `inited==INDEX' failed.

10.6.0 a3e3225cd3b816d47621e749e21a71b6a864a96a (Debug)

 
Core was generated by `/test/MD150421-mariadb-10.6.0-linux-x86_64-dbg/bin/mysqld --no-defaults --core-'.
 
Program terminated with signal SIGABRT, Aborted.
 
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
 
[Current thread is 1 (Thread 0x151bf00e9700 (LWP 4110476))]
 
(gdb) bt
 
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
 
#1  0x0000151bf2ca7859 in __GI_abort () at abort.c:79
 
#2  0x0000151bf2ca7729 in __assert_fail_base (fmt=0x151bf2e3d588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x5612acd7d995 "inited==INDEX", file=0x5612acb607ec "/test/10.6_dbg/sql/handler.h", line=3410, function=<optimized out>) at assert.c:92
 
#3  0x0000151bf2cb8f36 in __GI___assert_fail (assertion=assertion@entry=0x5612acd7d995 "inited==INDEX", file=file@entry=0x5612acb607ec "/test/10.6_dbg/sql/handler.h", line=line@entry=3410, function=function@entry=0x5612acb60904 "int handler::ha_index_end()") at assert.c:101
 
#4  0x00005612ac37ca28 in handler::ha_index_end (this=0x151ba4089280) at /test/10.6_dbg/sql/handler.h:3410
 
#5  opt_sum_query (thd=0x151ba4000db8, tables=@0x151ba4014d00: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x151ba4017ab8, last = 0x151ba4017ab8, elements = 1}, <No data fields>}, all_fields=@0x151ba4017868: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x151ba40151f8, last = 0x151ba40151f8, elements = 1}, <No data fields>}, conds=0x0) at /test/10.6_dbg/sql/opt_sum.cc:422
 
#6  0x00005612abf604c2 in JOIN::optimize_inner (this=this@entry=0x151ba4017540) at /test/10.6_dbg/sql/sql_select.cc:2169
 
#7  0x00005612abf60b40 in JOIN::optimize (this=this@entry=0x151ba4017540) at /test/10.6_dbg/sql/sql_select.cc:1630
 
#8  0x00005612abea9fdb in st_select_lex::optimize_unflattened_subqueries (this=0x151ba4013c70, const_only=const_only@entry=true) at /test/10.6_dbg/sql/sql_lex.cc:4886
 
#9  0x00005612ac097ff3 in JOIN::optimize_constant_subqueries (this=this@entry=0x151ba4016e90) at /test/10.6_dbg/sql/opt_subselect.cc:5589
 
#10 0x00005612abf5f7b1 in JOIN::optimize_inner (this=this@entry=0x151ba4016e90) at /test/10.6_dbg/sql/sql_select.cc:1937
 
#11 0x00005612abf60b40 in JOIN::optimize (this=this@entry=0x151ba4016e90) at /test/10.6_dbg/sql/sql_select.cc:1630
 
#12 0x00005612abf614a4 in mysql_select (thd=thd@entry=0x151ba4000db8, tables=0x151ba4014290, fields=@0x151ba4013dc0: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x151ba4014248, last = 0x151ba4014248, elements = 1}, <No data fields>}, conds=0x151ba4016328, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2147748608, result=0x151ba4016e68, unit=0x151ba4004f90, select_lex=0x151ba4013c70) at /test/10.6_dbg/sql/sql_select.cc:4735
 
#13 0x00005612abf617b9 in handle_select (thd=thd@entry=0x151ba4000db8, lex=lex@entry=0x151ba4004ec8, result=result@entry=0x151ba4016e68, setup_tables_done_option=setup_tables_done_option@entry=0) at /test/10.6_dbg/sql/sql_select.cc:419
 
#14 0x00005612abed48b5 in execute_sqlcom_select (thd=thd@entry=0x151ba4000db8, all_tables=0x151ba4014290) at /test/10.6_dbg/sql/sql_parse.cc:6244
 
#15 0x00005612abee177d in mysql_execute_command (thd=thd@entry=0x151ba4000db8) at /test/10.6_dbg/sql/sql_parse.cc:3940
 
#16 0x00005612abecda06 in mysql_parse (thd=thd@entry=0x151ba4000db8, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x151bf00e8410) at /test/10.6_dbg/sql/sql_parse.cc:8017
 
#17 0x00005612abedc7df in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x151ba4000db8, packet=packet@entry=0x151ba400b369 "SELECT a FROM t1 WHERE a=(SELECT MAX(a) FROM t1)", packet_length=packet_length@entry=48, blocking=blocking@entry=true) at /test/10.6_dbg/sql/sql_class.h:1331
 
#18 0x00005612abedfbd5 in do_command (thd=0x151ba4000db8, blocking=blocking@entry=true) at /test/10.6_dbg/sql/sql_parse.cc:1406
 
#19 0x00005612ac03977c in do_handle_one_connection (connect=<optimized out>, connect@entry=0x5612af7e9818, put_in_cache=put_in_cache@entry=true) at /test/10.6_dbg/sql/sql_connect.cc:1410
 
#20 0x00005612ac039d81 in handle_one_connection (arg=arg@entry=0x5612af7e9818) at /test/10.6_dbg/sql/sql_connect.cc:1312
 
#21 0x00005612ac4e7a03 in pfs_spawn_thread (arg=0x5612af6ffbd8) at /test/10.6_dbg/storage/perfschema/pfs.cc:2201
 
#22 0x0000151bf31b5609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 
#23 0x0000151bf2da4293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Bug confirmed present in:
MariaDB: 10.5.10 (dbg), 10.6.0 (dbg)

Bug (or feature/syntax) confirmed not present in:
MariaDB: 10.2.38 (dbg), 10.2.38 (opt), 10.3.29 (dbg), 10.3.29 (opt), 10.4.19 (dbg), 10.4.19 (opt), 10.5.10 (opt), 10.6.0 (opt)
MySQL: 5.5.62 (dbg), 5.5.62 (opt), 5.6.51 (dbg), 5.6.51 (opt), 5.7.33 (dbg), 5.7.33 (opt), 8.0.23 (dbg), 8.0.23 (opt)

Optimized build gives:

10.6.0 a3e3225cd3b816d47621e749e21a71b6a864a96a (Optimized)

 
ERROR 1399 (XAE07): XAER_RMFAIL: The command cannot be executed when global transaction is in the  PREPARED state

And this is also the result on 10.4, thus for this testcase there is a new regression in 10.5/10.6

As per Marko, "I guess the XA transaction is in a limbo state. Normally, DDL statements silently commit any open transaction. IMO, if XA has been requested, the DROP TABLE should return an error. Likewise, executing anything else than XA ROLLBACK or XA COMMIT after XA PREPARE is wrong and should return an error. So, this should actually belong to the runtime team."

Testcase seems non-sporadic.

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