Assertion `! is_set()' failed in Diagnostics_area::set_ok_status with derived table + subquery + concurrent DML

[Philip Stoev]

When executing concurrent queries such as:

CREATE TABLE transforms.insert_select_16453
SELECT alias1 . `col_datetime_key` AS field1 FROM (
  ( SELECT SQ1_alias1 . * FROM C AS SQ1_alias1 ) AS alias1 , ( SELECT SQ2_alias1 . * FROM C AS SQ2_alias1 ) AS alias2 )
WHERE ( alias1 . `col_int_nokey` , alias2 . `col_int_nokey` ) IN (
   SELECT SQ3_alias1 . `col_int_nokey` AS SQ3_field1 , SQ3_alias1 . `col_int_nokey` AS SQ3_field2 FROM BB AS SQ3_alias1
);

the server asserts as follows:

mysqld: sql_class.cc:563: void Diagnostics_area::set_ok_status(THD*, ha_rows, ulonglong, const char*): Assertion `! is_set()' failed.

# 2011-08-18T09:26:38 #6 0x00000033b58296e6 in __assert_fail () from /lib64/libc.so.6
# 2011-08-18T09:26:38 #7 0x000000000067598a in Diagnostics_area::set_ok_status (this=0xc1612f0, thd=0xc15f3f8, affected_rows_arg=0, last_insert_id_arg=0,
# 2011-08-18T09:26:38 message_arg=0x4f9aa730 "Records: 0 Duplicates: 0 Warnings: 0") at sql_class.cc:563
# 2011-08-18T09:26:38 #8 0x0000000000585487 in my_ok (thd=0xc15f3f8, affected_rows=0, id=0, message=0x4f9aa730 "Records: 0 Duplicates: 0 Warnings: 0") at sql_class.h:2686
# 2011-08-18T09:26:38 #9 0x000000000075c4d7 in select_insert::send_eof (this=0x2aaac40badf0) at sql_insert.cc:3421
# 2011-08-18T09:26:38 #10 0x000000000075c51f in select_create::send_eof (this=0x2aaac40badf0) at sql_insert.cc:4026
# 2011-08-18T09:26:38 #11 0x0000000000736532 in do_select (join=0x2aaac40611a0, fields=0xc161e90, table=0x0, procedure=0x0) at sql_select.cc:14727
# 2011-08-18T09:26:38 #12 0x0000000000756292 in JOIN::exec (this=0x2aaac40611a0) at sql_select.cc:2670
# 2011-08-18T09:26:38 #13 0x00000000007501aa in mysql_select (thd=0xc15f3f8, rref_pointer_array=0xc161fd8, tables=0x2aaac4083a70, wild_num=0, fields=..., conds=0x2aaac40babe8,
# 2011-08-18T09:26:38 og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2416200192, result=0x2aaac40badf0, unit=0xc1618a0, select_lex=0xc161d88)
# 2011-08-18T09:26:38 at sql_select.cc:2891
# 2011-08-18T09:26:38 #14 0x00000000007565c4 in handle_select (thd=0xc15f3f8, lex=0xc161800, result=0x2aaac40badf0, setup_tables_done_option=0) at sql_select.cc:283
# 2011-08-18T09:26:38 #15 0x00000000006a61a4 in mysql_execute_command (thd=0xc15f3f8) at sql_parse.cc:2721
# 2011-08-18T09:26:38 #16 0x00000000006adc05 in mysql_parse (thd=0xc15f3f8,
# 2011-08-18T09:26:38 rawbuf=0xc163260 "CREATE TABLE transforms.insert_select_16453 SELECT alias1 . `col_datetime_key` AS field1 FROM ( ( SELECT SQ1_alias1 . * FROM C AS SQ1_alias1 ) AS alias1 , ( SELECT SQ2_alias1 . * FROM C AS SQ2_alias1 ) AS alias2 ) WHERE ( alias1 . `col_int_nokey` , alias2 . `col_int_nokey` ) IN ( SELECT SQ3_alias1 . `col_int_nokey` AS SQ3_field1 , SQ3_alias1 . `col_int_nokey` AS SQ3_field2 FROM BB AS SQ3_alias1 )", length=403, found_semicolon=0x4f9abf08)
# 2011-08-18T09:26:38 at sql_parse.cc:6088
# 2011-08-18T09:26:38 #17 0x00000000006aea9d in dispatch_command (command=COM_QUERY, thd=0xc15f3f8,
# 2011-08-18T09:26:38 packet=0xc233549 "CREATE TABLE transforms.insert_select_16453 SELECT alias1 . `col_datetime_key` AS field1 FROM ( ( SELECT SQ1_alias1 . * FROM C AS SQ1_alias1 ) AS alias1 , ( SELECT SQ2_alias1 . * FROM C AS SQ2_alias1 ) AS alias2 ) WHERE ( alias1 . `col_int_nokey` , alias2 . `col_int_nokey` ) IN ( SELECT SQ3_alias1 . `col_int_nokey` AS SQ3_field1 , SQ3_alias1 . `col_int_nokey` AS SQ3_field2 FROM BB AS SQ3_alias1 )", packet_length=403) at sql_parse.cc:1208
# 2011-08-18T09:26:38 #18 0x00000000006b00ab in do_command (thd=0xc15f3f8) at sql_parse.cc:906
# 2011-08-18T09:26:38 #19 0x000000000069aa4b in handle_one_connection (arg=0xc15f3f8) at sql_connect.cc:1178
# 2011-08-18T09:26:38 #20 0x00000033b600673d in start_thread () from /lib64/libpthread.so.0
# 2011-08-18T09:26:38 #21 0x00000033b58d40cd in clone () from /lib64/libc.so.6

optimizer switch:

index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,index_condition_pushdown=on,derived_merge=off,derived_with_keys=off,firstmatch=off,loosescan=off,materialization=off,in_to_exists=on,semijoin=off,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=off,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=off,table_elimination=on

bzr version-info:

revision-id: <email address hidden>
date: 2011-08-17 14:10:32 +0300
build-date: 2011-08-18 09:39:38 +0300
revno: 3163
branch-nick: maria-5.3

Reproducible with maria-5.3. Not reproducible with mysql-5.5, maria-5.2 and maria-5.3 before the derived table changes.

[Philip Stoev (pstoev-askmonty)]

To reproduce with the RQG:

$ bzr branch lp-randgen

$ perl runall.pl --notnull --duration=60 --queries=300000000 --reporter=QueryTimeout,Deadlock,Backtrace,Shutdown --threads=4 --validator=Transformer --basedir=/home/philips/bzr/maria-5.3/ --transformers=ExecuteAsInsertSelect,ExecuteAsUpdateDelete --engine=InnoDB --mysqld=--innodb_stats_sample_pages=64 --seed=131332050 --grammar=/path/to/bug828514.yy

Please ignore all message from the RQG except for the final crash report.

[Philip Stoev (pstoev-askmonty)]

Each thread creates its own tables, so there should be no conflicting DDL statements.

Notice that the concurrent workload creates innodb deadlock errors -- CREATE ... SELECT may cause write locks on both participating tables?

[Michael Widenius (monty)]

Bug was not checking error conditions when calling skip_record(). Fixed in 5.3