[MDEV-7906] InnoDB: Failing assertion: prebuilt->sql_stat_start || trx->state == 1 on concurrent multi-table update Created: 2015-04-05  Updated: 2015-06-07  Resolved: 2015-06-07

Status: Closed
Project: MariaDB Server
Component/s: Optimizer
Affects Version/s: 5.5, 10.0, 10.1
Fix Version/s: 5.5.44

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Jan Lindström (Inactive)
Resolution: Fixed Votes: 0
Labels: verified

Sprint: 5.5.44

 Description   

Stack trace from 5.5 commit cc84ac3be41d9d6ac480d55449d5bf4e324cca10

 
InnoDB: Assertion failure in thread 140513694545664 in file row0sel.c line 3917
 
InnoDB: Failing assertion: prebuilt->sql_stat_start || trx->state == 1
 
 
 
# 2015-04-05T03:45:34 [2872] #3  <signal handler called>
 
# 2015-04-05T03:45:34 [2872] #4  0x00007fcbe2cb7165 in *__GI_raise (sig=<optimized out>) at ../nptl/sysdeps/unix/sysv/linux/raise.c:64
 
# 2015-04-05T03:45:34 [2872] #5  0x00007fcbe2cba3e0 in *__GI_abort () at abort.c:92
 
# 2015-04-05T03:45:34 [2872] #6  0x00000000009be1f2 in row_search_for_mysql (buf=0x7fcbba452578 "\377\377\217\217\217\217\217\217\217\217\217\217\217\217", mode=1, prebuilt=0x7fcbba548078, match_mode=0, direction=1) at 5.5/storage/xtradb/row/row0sel.c:3917
 
# 2015-04-05T03:45:34 [2872] #7  0x0000000000977b63 in ha_innobase::general_fetch (this=0x7fcbba545078, buf=0x7fcbba452578 "\377\377\217\217\217\217\217\217\217\217\217\217\217\217", direction=1, match_mode=0) at 5.5/storage/xtradb/handler/ha_innodb.cc:7340
 
# 2015-04-05T03:45:34 [2872] #8  0x0000000000977ce5 in ha_innobase::index_next (this=0x7fcbba545078, buf=0x7fcbba452578 "\377\377\217\217\217\217\217\217\217\217\217\217\217\217") at 5.5/storage/xtradb/handler/ha_innodb.cc:7390
 
# 2015-04-05T03:45:34 [2872] #9  0x00000000005cfbae in handler::ha_index_next (this=0x7fcbba545078, buf=0x7fcbba452578 "\377\377\217\217\217\217\217\217\217\217\217\217\217\217") at 5.5/sql/sql_class.h:4251
 
# 2015-04-05T03:45:34 [2872] #10 0x000000000068fac1 in join_read_next (info=0x7fcbc9e17128) at 5.5/sql/sql_select.cc:17855
 
# 2015-04-05T03:45:34 [2872] #11 0x000000000068d8d0 in sub_select (join=0x7fcbc9e49388, join_tab=0x7fcbc9e17078, end_of_records=false) at 5.5/sql/sql_select.cc:16932
 
# 2015-04-05T03:45:34 [2872] #12 0x000000000068d07c in do_select (join=0x7fcbc9e49388, fields=0x7fcbe4d95d10, table=0x0, procedure=0x0) at 5.5/sql/sql_select.cc:16575
 
# 2015-04-05T03:45:34 [2872] #13 0x000000000066bce3 in JOIN::exec (this=0x7fcbc9e49388) at 5.5/sql/sql_select.cc:2873
 
# 2015-04-05T03:45:34 [2872] #14 0x000000000066c4ed in mysql_select (thd=0x7fcbc9d53060, rref_pointer_array=0x7fcbc9d56cd0, tables=0x7fcbc9d7b2d8, wild_num=0, fields=..., conds=0x7fcbc9e49208, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=1342177408, result=0x7fcbc9e492c8, unit=0x7fcbc9d56380, select_lex=0x7fcbc9d56a60) at 5.5/sql/sql_select.cc:3094
 
# 2015-04-05T03:45:34 [2872] #15 0x00000000006eaba6 in mysql_multi_update (thd=0x7fcbc9d53060, table_list=0x7fcbc9d7b2d8, fields=0x7fcbc9d56b78, values=0x7fcbc9d57000, conds=0x7fcbc9e49208, options=0, handle_duplicates=DUP_ERROR, ignore=false, unit=0x7fcbc9d56380, select_lex=0x7fcbc9d56a60, result=0x7fcbe4d962c8) at 5.5/sql/sql_update.cc:1438
 
# 2015-04-05T03:45:34 [2872] #16 0x0000000000636d14 in mysql_execute_command (thd=0x7fcbc9d53060) at 5.5/sql/sql_parse.cc:2915
 
# 2015-04-05T03:45:34 [2872] #17 0x000000000063ece2 in mysql_parse (thd=0x7fcbc9d53060, rawbuf=0x7fcbc9d7b078 "UPDATE `C` AS alias1 LEFT JOIN `D` AS alias2 ON ( alias2.`col_date_key` <= alias1.`col_date_key` ) SET alias2.`pk` = -16143 WHERE alias2.`col_varchar_nokey` NOT IN ( SELECT `col_varchar_nokey` FROM `DD` )", length=204, parser_state=0x7fcbe4d96670) at 5.5/sql/sql_parse.cc:5909
 
# 2015-04-05T03:45:34 [2872] #18 0x0000000000632925 in dispatch_command (command=COM_QUERY, thd=0x7fcbc9d53060, packet=0x7fcbc9d58061 "UPDATE `C` AS alias1 LEFT JOIN `D` AS alias2 ON ( alias2.`col_date_key` <= alias1.`col_date_key` ) SET alias2.`pk` = -16143 WHERE alias2.`col_varchar_nokey` NOT IN ( SELECT `col_varchar_nokey` FROM `DD` )", packet_length=204) at 5.5/sql/sql_parse.cc:1079
 
# 2015-04-05T03:45:34 [2872] #19 0x0000000000631ab1 in do_command (thd=0x7fcbc9d53060) at 5.5/sql/sql_parse.cc:793
 
# 2015-04-05T03:45:34 [2872] #20 0x0000000000734122 in do_handle_one_connection (thd_arg=0x7fcbc9d53060) at 5.5/sql/sql_connect.cc:1266
 
# 2015-04-05T03:45:34 [2872] #21 0x0000000000733be1 in handle_one_connection (arg=0x7fcbc9d53060) at 5.5/sql/sql_connect.cc:1181
 
# 2015-04-05T03:45:34 [2872] #22 0x00007fcbe4aaab50 in start_thread (arg=<optimized out>) at pthread_create.c:304
 
# 2015-04-05T03:45:34 [2872] #23 0x00007fcbe2d6095d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112

RQG command line

 
perl ./runall-new.pl --grammar=1.yy --threads=3 --duration=300 --queries=100M  --engine=InnoDB --basedir=<your basedir> --vardir=<your vardir>

RQG grammar 1.yy

 
thread1:
 
  UPDATE `DD` 
  SET `pk` = _smallint 
  WHERE `col_varchar_key` = _char 
;
 
 
 
thread2:
 
  UPDATE `DD` AS alias1, `E` AS alias2 
  SET alias1.`pk` = _smallint 
  WHERE alias1.`col_varchar_nokey` = alias2.`col_varchar_nokey`
 
;
 
 
 
thread3:
 
  UPDATE `C` AS alias1 LEFT JOIN `D` AS alias2 
    ON ( alias2.`col_date_key` <= alias1.`col_date_key` ) 
  SET alias2.`pk` = _smallint 
  WHERE alias2.`col_varchar_nokey` NOT IN ( SELECT `col_varchar_nokey` FROM `DD` )
 
;



 Comments   
Comment by Jan Lindström (Inactive) [ 2015-04-05 ]

Easily repeatable (every time) with XtraDB and commit 26920cc6a006b4fe74ab0092b2d394199fe51977, could not repeat with Oracle MySQL 5.5.42 and Percona MySQL Version:5.5.42-37.1 (two tries). Do not know how to test with innodb_plugin, following does not seem to work:

perl ./runall-new.pl --grammar=5.yy --threads=3 --duration=300 --queries=100M  --engine=InnoDB --basedir=/home/jan/mysql/5.5-git --vardir=/dev/shm --mysqld=--ignore_builtin_innodb --mysqld=--plugin_load=innodb=ha_innodb.so --mysqld=plugin_dir=/home/jan/mysql/5.5-git/storage/innobase

Comment by Elena Stepanova [ 2015-04-05 ]

You've missed "dash-dash" before plugin_dir. Otherwise the command line is fine.

Anyway, it's just as easily repeatable with InnoDB plugin. And I had the same results as you with Percona and MySQL – also couldn't repeat it there.

Comment by Sergei Petrunia [ 2015-04-23 ]

The query that causes the crash for me is always the UPDATE ... LEFT JOIN query:

Query (0x7ff4780051c8): UPDATE `C` AS alias1 LEFT JOIN `D` AS alias2 ON ( alias2.`col_date_key` <= alias1.`col_date_key` ) SET alias2.`pk` = -16143 WHERE alias2.`col_varchar_nokey` NOT IN ( SELECT `col_varchar_nokey` FROM `DD` )

Query (0x7f11cc0051c8): UPDATE `C` AS alias1 LEFT JOIN `D` AS alias2 ON ( alias2.`col_date_key` <= alias1.`col_date_key` ) SET alias2.`pk` = -16143 WHERE alias2.`col_varchar_nokey` NOT IN ( SELECT `col_varchar_nokey` FROM `DD` )

Comment by Sergei Petrunia [ 2015-04-23 ]

jplindst found the stack trace where SQL layer continues execution despite having gotten an error from the storage engine:

#0  0x00007f8b9a015621 in __pthread_kill (threadid=<optimized out>, signo=6) at ../nptl/sysdeps/unix/sysv/linux/pthread_kill.c:61
 
#1  0x0000000000ce1422 in my_write_core (sig=6) at /home/jan/mysql/5.5-git/mysys/stacktrace.c:457
 
#2  0x00000000007c3c32 in handle_fatal_signal (sig=6) at /home/jan/mysql/5.5-git/sql/signal_handler.cc:262
 
#3  <signal handler called>
 
#4  0x00007f8b9966fcc9 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
 
#5  0x00007f8b996730d8 in __GI_abort () at abort.c:89
 
#6  0x0000000000abec79 in ha_innobase::index_read (this=0x7f8b4400ace8, buf=0x7f8b4400cd28 "\377\377", key_ptr=0x0, key_len=0, find_
 
flag=HA_READ_AFTER_KEY) at /home/jan/mysql/5.5-git/storage/xtradb/handler/ha_innodb.cc:7149
 
#7  0x0000000000abf95a in ha_innobase::index_first (this=0x7f8b4400ace8, buf=0x7f8b4400cd28 "\377\377") at /home/jan/mysql/5.5-git/s
 
torage/xtradb/handler/ha_innodb.cc:7487
 
#8  0x0000000000abfb3e in ha_innobase::rnd_next (this=0x7f8b4400ace8, buf=0x7f8b4400cd28 "\377\377") at /home/jan/mysql/5.5-git/stor
 
age/xtradb/handler/ha_innodb.cc:7584
 
#9  0x000000000059d268 in handler::ha_rnd_next (this=0x7f8b4400ace8, buf=0x7f8b4400cd28 "\377\377") at /home/jan/mysql/5.5-git/sql/s
 
ql_class.h:4325
 
#10 0x00000000008edb74 in rr_sequential (info=0x7f8b440141c8) at /home/jan/mysql/5.5-git/sql/records.cc:467
 
#11 0x00000000006626d5 in join_init_read_record (tab=0x7f8b44014118) at /home/jan/mysql/5.5-git/sql/sql_select.cc:17795
 
#12 0x000000000066076d in sub_select (join=0x7f8b44009c10, join_tab=0x7f8b44014118, end_of_records=false) at /home/jan/mysql/5.5-git
 
/sql/sql_select.cc:16908
 
#13 0x0000000000660048 in do_select (join=0x7f8b44009c10, fields=0x7f8b44008400, table=0x0, procedure=0x0) at /home/jan/mysql/5.5-gi
 
t/sql/sql_select.cc:16573
 
#14 0x000000000063d54e in JOIN::exec (this=0x7f8b44009c10) at /home/jan/mysql/5.5-git/sql/sql_select.cc:2871
 
#15 0x0000000000861870 in subselect_single_select_engine::exec (this=0x7f8b440070d0) at /home/jan/mysql/5.5-git/sql/item_subselect.c
 
c:3231
 
#16 0x000000000085a384 in Item_subselect::exec (this=0x7f8b440092f8) at /home/jan/mysql/5.5-git/sql/item_subselect.cc:655
 
#17 0x000000000085a8c4 in Item_in_subselect::exec (this=0x7f8b440092f8) at /home/jan/mysql/5.5-git/sql/item_subselect.cc:828
 
#18 0x000000000085cd31 in Item_in_subselect::val_bool (this=0x7f8b440092f8) at /home/jan/mysql/5.5-git/sql/item_subselect.cc:1654
 
#19 0x0000000000569f35 in Item::val_bool_result (this=0x7f8b440092f8) at /home/jan/mysql/5.5-git/sql/item.h:981
 
#20 0x00000000007f8ab7 in Item_in_optimizer::val_int (this=0x7f8b4400a1b0) at /home/jan/mysql/5.5-git/sql/item_cmpfunc.cc:1732
 
#21 0x0000000000569ea9 in Item::val_int_result (this=0x7f8b4400a1b0) at /home/jan/mysql/5.5-git/sql/item.h:977
 
#22 0x00000000007ea14f in Item_cache_int::cache_value (this=0x7f8b44014458) at /home/jan/mysql/5.5-git/sql/item.cc:8866
 
#23 0x00000000007f164c in Item_cache_wrapper::cache (this=0x7f8b44016f08) at /home/jan/mysql/5.5-git/sql/item.cc:7670
 
#24 0x00000000007e731b in Item_cache_wrapper::val_bool (this=0x7f8b44016f08) at /home/jan/mysql/5.5-git/sql/item.cc:7834
 
#25 0x00000000007f4919 in Item_func_not::val_int (this=0x7f8b44009478) at /home/jan/mysql/5.5-git/sql/item_cmpfunc.cc:335
 
#26 0x0000000000674d6b in Item_func_trig_cond::val_int (this=0x7f8b44011cc8) at /home/jan/mysql/5.5-git/sql/item_cmpfunc.h:486
 
#27 0x00000000007d226f in Item::val_bool (this=0x7f8b44011cc8) at /home/jan/mysql/5.5-git/sql/item.cc:215
 
#28 0x0000000000802bd7 in Item_cond_and::val_int (this=0x7f8b44012f48) at /home/jan/mysql/5.5-git/sql/item_cmpfunc.cc:4695
 
#29 0x0000000000661063 in evaluate_null_complemented_join_record (join=0x7f8b440095f8, join_tab=0x7f8b44012868) at /home/jan/mysql/5
 
.5-git/sql/sql_select.cc:17194
 
#30 0x00000000006609b4 in sub_select (join=0x7f8b440095f8, join_tab=0x7f8b44012868, end_of_records=false) at /home/jan/mysql/5.5-git
 
/sql/sql_select.cc:16955
 
#31 0x0000000000660e6d in evaluate_join_record (join=0x7f8b440095f8, join_tab=0x7f8b44012548, error=0) at /home/jan/mysql/5.5-git/sq
 
l/sql_select.cc:17130
 
#32 0x00000000006607cf in sub_select (join=0x7f8b440095f8, join_tab=0x7f8b44012548, end_of_records=false) at /home/jan/mysql/5.5-git
 
/sql/sql_select.cc:16911
 
#33 0x0000000000660048 in do_select (join=0x7f8b440095f8, fields=0x7f8b9aafec00, table=0x0, procedure=0x0) at /home/jan/mysql/5.5-gi
 
t/sql/sql_select.cc:16573
 
#34 0x000000000063d54e in JOIN::exec (this=0x7f8b440095f8) at /home/jan/mysql/5.5-git/sql/sql_select.cc:2871
 
#35 0x000000000063dd5d in mysql_select (thd=0x3e3c920, rref_pointer_array=0x3e40590, tables=0x7f8b44005428, wild_num=0, fields=..., 
conds=0x7f8b44009478, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=1342177408, result=0x7f8b44009538, 
unit=0x3e3fc40, select_lex=0x3e40320) at /home/jan/mysql/5.5-git/sql/sql_select.cc:3092
 
#36 0x00000000006c1db5 in mysql_multi_update (thd=0x3e3c920, table_list=0x7f8b44005428, fields=0x3e40438, values=0x3e408c0, conds=0x
 
7f8b44009478, options=0, handle_duplicates=DUP_ERROR, ignore=false, unit=0x3e3fc40, select_lex=0x3e40320, result=0x7f8b9aafef20) at 
/home/jan/mysql/5.5-git/sql/sql_update.cc:1438
 
#37 0x00000000006069ae in mysql_execute_command (thd=0x3e3c920) at /home/jan/mysql/5.5-git/sql/sql_parse.cc:2915

Comment by Sergei Petrunia [ 2015-04-23 ]

A [crude] patch that seems to make the crash go away: https://gist.github.com/spetrunia/ae442eba2ffe4a72f149

Comment by Jan Lindström (Inactive) [ 2015-04-23 ]

Reassigning to Sergei as he has found the actual problem.

Comment by Jan Lindström (Inactive) [ 2015-04-23 ]

Regression testing was not fully successful with suggested fix:

Failing test(s): main.select_pkeycache main.join_cache main.join_outer main.join main.join_nested main.table_elim main.view main.select

Comment by Sergei Petrunia [ 2015-04-23 ]

Ok, there was a trivial typo in the patch, which now is fixed

Comment by Jan Lindström (Inactive) [ 2015-06-04 ]

Only sql_class.cc needs review:

http://lists.askmonty.org/pipermail/commits/2015-June/007995.html

Comment by Sergei Golubchik [ 2015-06-04 ]

as discussed on irc:

  • no need to change sql_class.cc
  • condition should be something like

    if (prebuilt->sql_stat_start == false || prebuilt->trx == NULL || prebuilt->trx->state != TRX_STARTED)

  • xtradb might use an assert(thd->is_error());
Generated at Thu Feb 08 07:23:10 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.