[MDEV-5930] Server crashes in thd_get_ha_data on CREATE OR REPLACE TABLE Created: 2014-03-22  Updated: 2014-03-29  Resolved: 2014-03-29

Status: Closed
Project: MariaDB Server
Component/s: None
Affects Version/s: None
Fix Version/s: 10.0.10

Type: Bug Priority: Critical
Reporter: Elena Stepanova Assignee: Michael Widenius
Resolution: Fixed Votes: 0
Labels: None


 Description   

Variant 1: deterministic test involving TokuDB

CREATE TABLE t1 (a INT);
 
CREATE TABLE t2 (a INT) ENGINE=TokuDB;
 
CREATE OR REPLACE TABLE t1 AS SELECT * FROM t2;
 

#4  0x0000000000634ce5 in thd_get_ha_data (thd=0x7f98843cc070, hton=0x7f988b3f8a70) at 10.0/sql/sql_class.cc:636
 
#5  0x0000000000929920 in binlog_reset_cache (thd=0x7f98843cc070) at 10.0/sql/log.cc:2059
 
#6  0x000000000065e6ba in select_create::abort_result_set (this=0x7f98679a2068) at 10.0/sql/sql_insert.cc:4348
 
#7  0x00000000006a6192 in handle_select (thd=0x7f98843cc070, lex=0x7f98843cfcb0, result=0x7f98679a2068, setup_tables_done_option=0) at 10.0/sql/sql_select.cc:378
 
#8  0x000000000067430b in mysql_execute_command (thd=0x7f98843cc070) at 10.0/sql/sql_parse.cc:3032
 
#9  0x000000000067d6db in mysql_parse (thd=0x7f98843cc070, rawbuf=0x7f98679a1088 "CREATE OR REPLACE TABLE t1 AS SELECT * FROM t2", length=46, parser_state=0x7f988d823610) at 10.0/sql/sql_parse.cc:6447
 
#10 0x00000000006704a8 in dispatch_command (command=COM_QUERY, thd=0x7f98843cc070, packet=0x7f98802da071 "CREATE OR REPLACE TABLE t1 AS SELECT * FROM t2", packet_length=46) at 10.0/sql/sql_parse.cc:1308
 
#11 0x000000000066f84a in do_command (thd=0x7f98843cc070) at 10.0/sql/sql_parse.cc:1005
 
#12 0x0000000000789f02 in do_handle_one_connection (thd_arg=0x7f98843cc070) at 10.0/sql/sql_connect.cc:1379
 
#13 0x0000000000789c55 in handle_one_connection (arg=0x7f98843cc070) at 10.0/sql/sql_connect.cc:1293
 
#14 0x0000000000a2f27c in pfs_spawn_thread (arg=0x7f987ff9fa30) at 10.0/storage/perfschema/pfs.cc:1853
 
#15 0x00007f988d457b50 in start_thread (arg=<optimized out>) at pthread_create.c:304
 
#16 0x00007f988b962a7d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
 
#17 0x0000000000000000 in ?? ()

Variant 2: concurrent test with KILL QUERY (without TokuDB)

RQG grammar (bug.yy):

query_init:
 
	CREATE TABLE IF NOT EXISTS `t1` (`f1` INT) ENGINE=InnoDB;
 
 
 
query:
 
	INSERT INTO `t1` VALUES ( _digit ) |
 
	DELETE FROM `t1` WHERE `f1` < _digit LIMIT 1 ;
 
 
 
thread3:
 
	CREATE OR REPLACE TABLE `t2` AS SELECT * FROM `t1`; 
 
 
thread4:
 
	KILL QUERY CONNECTION_ID()-1 | query ;

RQG command line (starts the server):

perl ./runall.pl --threads=8 --duration=120 --queries=100M --skip-gendata  --grammar=bug.yy  --basedir=<basedir>

Or, if the server is already running on port 3306:

perl ./gentest.pl --threads=8 --duration=120 --queries=100M   --grammar=bug.yy   --dsn="dbi:mysql:host=127.0.0.1:port=3306:user=root:database=test"
 

# 2014-03-22T15:15:59 #3  <signal handler called>
 
# 2014-03-22T15:15:59 #4  0x0000000000602445 in thd_get_ha_data (thd=0x7fedeae15070, hton=0x7fedfa7df270) at 10.0/sql/sql_class.cc:636
 
# 2014-03-22T15:15:59 #5  0x000000000090a199 in binlog_reset_cache (thd=0x7fedeae15070) at 10.0/sql/log.cc:2059
 
# 2014-03-22T15:15:59 #6  0x000000000062cb48 in select_create::abort_result_set (this=0x7fede385a088) at 10.0/sql/sql_insert.cc:4348
 
# 2014-03-22T15:15:59 #7  0x0000000000676192 in handle_select (thd=0x7fedeae15070, lex=0x7fedeae18cb0, result=0x7fede385a088, setup_tables_done_option=0) at 10.0/sql/sql_select.cc:378
 
# 2014-03-22T15:15:59 #8  0x0000000000642a09 in mysql_execute_command (thd=0x7fedeae15070) at 10.0/sql/sql_parse.cc:3032
 
# 2014-03-22T15:15:59 #9  0x000000000064bf8a in mysql_parse (thd=0x7fedeae15070, rawbuf=0x7fede3859088 "CREATE OR REPLACE TABLE `t2` AS SELECT * FROM `t1`", length=50, parser_state=0x7fedfdda25c0) at 10.0/sql/sql_parse.cc:6447
 
# 2014-03-22T15:15:59 #10 0x000000000063ea82 in dispatch_command (command=COM_QUERY, thd=0x7fedeae15070, packet=0x7fedeaed0071 "CREATE OR REPLACE TABLE `t2` AS SELECT * FROM `t1`", packet_length=50) at 10.0/sql/sql_parse.cc:1308
 
# 2014-03-22T15:15:59 #11 0x000000000063dddd in do_command (thd=0x7fedeae15070) at 10.0/sql/sql_parse.cc:1005
 
# 2014-03-22T15:15:59 #12 0x0000000000763337 in do_handle_one_connection (thd_arg=0x7fedeae15070) at 10.0/sql/sql_connect.cc:1379
 
# 2014-03-22T15:15:59 #13 0x000000000076309d in handle_one_connection (arg=0x7fedeae15070) at 10.0/sql/sql_connect.cc:1293
 
# 2014-03-22T15:15:59 #14 0x0000000000d67356 in pfs_spawn_thread (arg=0x7fedf0ff2710) at 10.0/storage/perfschema/pfs.cc:1853
 
# 2014-03-22T15:15:59 #15 0x00007fedff1cff6e in start_thread (arg=0x7fedfdda3700) at pthread_create.c:311
 
# 2014-03-22T15:15:59 #16 0x00007fedfe0b49cd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:113

Stack traces from:

revision-id: knielsen@knielsen-hq.org-20140321123055-8ch69qymsj1xqmw4
 
date: 2014-03-21 13:30:55 +0100
 
build-date: 2014-03-22 15:17:33 +0400
 
revno: 4076
 
branch-nick: 10.0



 Comments   
Comment by Elena Stepanova [ 2014-03-22 ]

Variation of the stack trace if the newly created table is also TokuDB (for further search):

CREATE TABLE t1 (a INT);
 
CREATE TABLE t2 (a INT) ENGINE=TokuDB;
 
CREATE OR REPLACE TABLE t1 ENGINE=TokuDB AS SELECT * FROM t2;
 

#2  0x000000000085b9e1 in handle_fatal_signal (sig=11) at 10.0/sql/signal_handler.cc:262
 
#3  <signal handler called>
 
#4  0x00007fa9f91052b6 in ft_loader_close_and_redirect (loader=0x7fa9e7f52430) at 10.0/storage/tokudb/ft-index/src/loader.cc:222
 
#5  0x00007fa9f91060f0 in toku_loader_close (loader=0x7fa9e7f52430) at 10.0/storage/tokudb/ft-index/src/loader.cc:469
 
#6  0x00007fa9f9017c4a in ha_tokudb::end_bulk_insert (this=0x7fa9e7d42088, abort=false) at 10.0/storage/tokudb/ha_tokudb.cc:3439
 
#7  0x00007fa9f9018083 in ha_tokudb::end_bulk_insert (this=0x7fa9e7d42088) at 10.0/storage/tokudb/ha_tokudb.cc:3503
 
#8  0x000000000065ec94 in handler::ha_end_bulk_insert (this=0x7fa9e7d42088) at 10.0/sql/handler.h:2651
 
#9  0x000000000065cd60 in select_insert::abort_result_set (this=0x7fa9e7f50090) at 10.0/sql/sql_insert.cc:3750
 
#10 0x000000000065e4e3 in select_create::abort_result_set (this=0x7fa9e7f50090) at 10.0/sql/sql_insert.cc:4317
 
#11 0x00000000006a6192 in handle_select (thd=0x7faa047cc070, lex=0x7faa047cfcb0, result=0x7fa9e7f50090, setup_tables_done_option=0) at 10.0/sql/sql_select.cc:378
 
#12 0x000000000067430b in mysql_execute_command (thd=0x7faa047cc070) at 10.0/sql/sql_parse.cc:3032
 
#13 0x000000000067d6db in mysql_parse (thd=0x7faa047cc070, rawbuf=0x7fa9e7f4f088 "CREATE OR REPLACE TABLE t1 ENGINE=TokuDB AS SELECT * FROM t2", length=60, parser_state=0x7faa0dc3d610) at 10.0/sql/sql_parse.cc:6447
 
#14 0x00000000006704a8 in dispatch_command (command=COM_QUERY, thd=0x7faa047cc070, packet=0x7faa006da071 "CREATE OR REPLACE TABLE t1 ENGINE=TokuDB AS SELECT * FROM t2", packet_length=60) at 10.0/sql/sql_parse.cc:1308
 
#15 0x000000000066f84a in do_command (thd=0x7faa047cc070) at 10.0/sql/sql_parse.cc:1005
 
#16 0x0000000000789f02 in do_handle_one_connection (thd_arg=0x7faa047cc070) at 10.0/sql/sql_connect.cc:1379
 
#17 0x0000000000789c55 in handle_one_connection (arg=0x7faa047cc070) at 10.0/sql/sql_connect.cc:1293
 
#18 0x0000000000a2f27c in pfs_spawn_thread (arg=0x7faa0039fa30) at 10.0/storage/perfschema/pfs.cc:1853
 
#19 0x00007faa0d8bab50 in start_thread (arg=<optimized out>) at pthread_create.c:304
 
#20 0x00007faa0bdc5a7d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112

Comment by Elena Stepanova [ 2014-03-22 ]

Yet another variation of the test case and, importantly, stack trace:

CREATE TABLE t1 (pk INT PRIMARY KEY, a INT, INDEX(a)) ENGINE=TokuDB;
 
CREATE TABLE t2 ENGINE=TokuDB AS SELECT * FROM t1;
 
CREATE OR REPLACE TABLE t1 ENGINE=TokuDB AS SELECT * FROM t2;
 

#3  <signal handler called>
 
#4  0x00007faa068533e8 in toku_db_get_range_lock (db=0x7fa9f573e180, txn=0x7fa9f5607800, left_key=0x7faa06beb130, right_key=0x7faa06beb150, lock_type=toku::lock_request::READ) at 10.0/storage/tokudb/ft-index/src/ydb_row_lock.cc:234
 
#5  0x00007faa068524b3 in c_set_bounds (dbc=0x7fa9f54d7080, left_key=0x7faa06beb130, right_key=0x7faa06beb150, pre_acquire=true, out_of_range_error=0) at 10.0/storage/tokudb/ft-index/src/ydb_cursor.cc:734
 
#6  0x00007faa0681f9a1 in ha_tokudb::prelock_range (this=0x7fa9f55ae088, start_key=0x0, end_key=0x0) at 10.0/storage/tokudb/ha_tokudb.cc:5836
 
#7  0x00007faa0681ebb0 in ha_tokudb::rnd_init (this=0x7fa9f55ae088, scan=true) at 10.0/storage/tokudb/ha_tokudb.cc:5647
 
#8  0x000000000060bd4f in handler::ha_rnd_init (this=0x7fa9f55ae088, scan=true) at 10.0/sql/handler.h:2593
 
#9  0x00000000008622e1 in handler::ha_rnd_init_with_error (this=0x7fa9f55ae088, scan=true) at 10.0/sql/handler.cc:2672
 
#10 0x000000000098dc0f in init_read_record (info=0x7fa9f5523c88, thd=0x7faa11fcc070, table=0x7fa9f549e070, select=0x7fa9f55c3288, use_record_cache=1, print_error=true, disable_rr_cache=false) at 10.0/sql/records.cc:277
 
#11 0x00000000006d3c7c in join_init_read_record (tab=0x7fa9f5523be0) at 10.0/sql/sql_select.cc:18325
 
#12 0x00000000006d1c18 in sub_select (join=0x7fa9f5456170, join_tab=0x7fa9f5523be0, end_of_records=false) at 10.0/sql/sql_select.cc:17435
 
#13 0x00000000006d14df in do_select (join=0x7fa9f5456170, fields=0x7faa11fd0578, table=0x0, procedure=0x0) at 10.0/sql/sql_select.cc:17100
 
#14 0x00000000006af15a in JOIN::exec_inner (this=0x7fa9f5456170) at 10.0/sql/sql_select.cc:3065
 
#15 0x00000000006ac66c in JOIN::exec (this=0x7fa9f5456170) at 10.0/sql/sql_select.cc:2355
 
#16 0x00000000006af9eb in mysql_select (thd=0x7faa11fcc070, rref_pointer_array=0x7faa11fd06d8, tables=0x7fa9f54558e0, wild_num=1, fields=..., conds=0x0, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2416184064, result=0x7fa9f5456090, unit=0x7faa11fcfd78, select_lex=0x7faa11fd0460) at 10.0/sql/sql_select.cc:3292
 
#17 0x00000000006a611b in handle_select (thd=0x7faa11fcc070, lex=0x7faa11fcfcb0, result=0x7fa9f5456090, setup_tables_done_option=0) at 10.0/sql/sql_select.cc:372
 
#18 0x000000000067430b in mysql_execute_command (thd=0x7faa11fcc070) at 10.0/sql/sql_parse.cc:3032
 
#19 0x000000000067d6db in mysql_parse (thd=0x7faa11fcc070, rawbuf=0x7fa9f5455088 "CREATE OR REPLACE TABLE t1 ENGINE=TokuDB AS SELECT * FROM t2", length=60, parser_state=0x7faa1b24d610) at 10.0/sql/sql_parse.cc:6447
 
#20 0x00000000006704a8 in dispatch_command (command=COM_QUERY, thd=0x7faa11fcc070, packet=0x7faa0deda071 "CREATE OR REPLACE TABLE t1 ENGINE=TokuDB AS SELECT * FROM t2", packet_length=60) at 10.0/sql/sql_parse.cc:1308
 
#21 0x000000000066f84a in do_command (thd=0x7faa11fcc070) at 10.0/sql/sql_parse.cc:1005
 
#22 0x0000000000789f02 in do_handle_one_connection (thd_arg=0x7faa11fcc070) at 10.0/sql/sql_connect.cc:1379
 
#23 0x0000000000789c55 in handle_one_connection (arg=0x7faa11fcc070) at 10.0/sql/sql_connect.cc:1293
 
#24 0x0000000000a2f27c in pfs_spawn_thread (arg=0x7faa0db9fa30) at 10.0/storage/perfschema/pfs.cc:1853
 
#25 0x00007faa1af30b50 in start_thread (arg=<optimized out>) at pthread_create.c:304
 
#26 0x00007faa1943ba7d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112

Comment by Elena Stepanova [ 2014-03-23 ]

The first test case with binary log enabled:

CREATE TABLE t1 (a INT);
 
CREATE TABLE t2 (a INT) ENGINE=TokuDB;
 
CREATE OR REPLACE TABLE t1 AS SELECT * FROM t2;
 

[ERROR] TokuDB:  toku_db_cursor_internal: Transaction cannot do work when child exists
 
 
 
mysqld: 10.0/sql/log.cc:5405: int MYSQL_BIN_LOG::remove_pending_rows_event(THD*, bool): Assertion `cache_mngr' failed.
 
140323 17:12:28 [ERROR] mysqld got signal 6 ;
 
 
 
 
 
#5  0x00007f062a1d76f0 in *__GI_abort () at abort.c:92
 
#6  0x00007f062a1cd621 in *__GI___assert_fail (assertion=0xffc53d "cache_mngr", file=<optimized out>, line=5405, function=0xffee40 "int MYSQL_BIN_LOG::remove_pending_rows_event(THD*, bool)") at assert.c:81
 
#7  0x00000000009326eb in MYSQL_BIN_LOG::remove_pending_rows_event (this=0x1882c60, thd=0x7f060bfbd070, is_transactional=true) at 10.0/sql/log.cc:5405
 
#8  0x0000000000641aa7 in THD::binlog_remove_pending_rows_event (this=0x7f060bfbd070, clear_maps=true, is_transactional=true) at 10.0/sql/sql_class.cc:5711
 
#9  0x0000000000929959 in binlog_reset_cache (thd=0x7f060bfbd070) at 10.0/sql/log.cc:2061
 
#10 0x000000000065e6ba in select_create::abort_result_set (this=0x7f05fdc14068) at 10.0/sql/sql_insert.cc:4348
 
#11 0x00000000006a6192 in handle_select (thd=0x7f060bfbd070, lex=0x7f060bfc0cb0, result=0x7f05fdc14068, setup_tables_done_option=0) at 10.0/sql/sql_select.cc:378
 
#12 0x000000000067430b in mysql_execute_command (thd=0x7f060bfbd070) at 10.0/sql/sql_parse.cc:3032
 
#13 0x000000000067d6db in mysql_parse (thd=0x7f060bfbd070, rawbuf=0x7f05fdc13088 "CREATE OR REPLACE TABLE t1 AS SELECT * FROM t2", length=46, parser_state=0x7f062c0f4610) at 10.0/sql/sql_parse.cc:6447
 
#14 0x00000000006704a8 in dispatch_command (command=COM_QUERY, thd=0x7f060bfbd070, packet=0x7f060c297071 "CREATE OR REPLACE TABLE t1 AS SELECT * FROM t2", packet_length=46) at 10.0/sql/sql_parse.cc:1308
 
#15 0x000000000066f84a in do_command (thd=0x7f060bfbd070) at 10.0/sql/sql_parse.cc:1005
 
#16 0x0000000000789f02 in do_handle_one_connection (thd_arg=0x7f060bfbd070) at 10.0/sql/sql_connect.cc:1379
 
#17 0x0000000000789c55 in handle_one_connection (arg=0x7f060bfbd070) at 10.0/sql/sql_connect.cc:1293
 
#18 0x0000000000a2f288 in pfs_spawn_thread (arg=0x7f0605298490) at 10.0/storage/perfschema/pfs.cc:1853
 
#19 0x00007f062bd71b50 in start_thread (arg=<optimized out>) at pthread_create.c:304
 
#20 0x00007f062a27ca7d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112

Comment by Michael Widenius [ 2014-03-23 ]

Problem was that I had forgot to check if binary logging was enabled when clearing the transaction cache.
Now fixed.

Comment by Michael Widenius [ 2014-03-29 ]

Pushed into 10.0

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