Bug #46462 Server crashes on select with concurrent update
Submitted: 29 Jul 2009 22:14 Modified: 11 Oct 2009 9:19
Reporter: Elena Stepanova Email Updates:
Status: Can't repeat Impact on me:
None 
Category:MySQL Server Severity:S2 (Serious)
Version:5.4.4-alpha OS:Any
Assigned to: CPU Architecture:Any
Tags: regression

[29 Jul 2009 22:14] Elena Stepanova
Description:
While running 2 parallel threads, one of which performs updates and another one selects (from a function), server crashes with the stack trace as below.

(gdb) bt
#0  0x00000033a8c0b122 in pthread_kill () from /lib64/libpthread.so.0
#1  0x0000000000a2ecfe in my_write_core (sig=11) at stacktrace.c:309
#2  0x0000000000663da5 in handle_segfault (sig=11) at mysqld.cc:2718
#3  <signal handler called>
#4  0x000000000090238d in read_view_sees_trx_id (view=0x0, trx_id={high = 0, low = 773})
    at ../../storage/innobase/include/read0read.ic:53
#5  0x0000000000902196 in lock_clust_rec_cons_read_sees (rec=0x2aaaab1c40b5 "", index=0x2aaaaacdfcb8, offsets=0x45573a90,
    view=0x0) at lock/lock0lock.c:485
#6  0x0000000000946e8c in row_search_for_mysql (buf=0x6ae45c0 "Ш", mode=1, prebuilt=0x2aaaaacd00b8, match_mode=0, direction=1)
    at row/row0sel.c:4067
#7  0x00000000008c0189 in ha_innobase::general_fetch (this=0x6ae4318, buf=0x6ae45c0 "Ш", direction=1, match_mode=0)
    at handler/ha_innodb.cc:4671
#8  0x00000000008c02e8 in ha_innobase::rnd_next (this=dwarf2_read_address: Corrupted DWARF expression.
) at handler/ha_innodb.cc:4860
#9  0x00000000007b97ad in rr_sequential (info=0x2aaaac02de00) at records.cc:390
#10 0x00000000006f0e66 in sub_select (join=0x2aaaac02f3a8, join_tab=0x2aaaac02dd78, end_of_records=false) at sql_select.cc:16276
#11 0x00000000006fea39 in do_select (join=0x2aaaac02f3a8, fields=0x2aaaac034ff0, table=0x0, procedure=0x0) at sql_select.cc:15817
#12 0x000000000071bc74 in JOIN::exec (this=0x2aaaac02f3a8) at sql_select.cc:2900
#13 0x00000000007163f1 in mysql_select (thd=0x6acf620, rref_pointer_array=0x6bfe320, tables=0x6bfef48, wild_num=0,
    fields=@0x6bfe240, conds=0x6c00890, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2147764736,
    result=0x6bfee00, unit=0x6bfdcd0, select_lex=0x6bfe138) at sql_select.cc:3091
#14 0x000000000071bf92 in handle_select (thd=0x6acf620, lex=0x6bfdc30, result=0x6bfee00, setup_tables_done_option=0)
    at sql_select.cc:306
#15 0x0000000000673849 in execute_sqlcom_select (thd=0x6acf620, all_tables=0x6bfef48) at sql_parse.cc:4927
#16 0x0000000000674942 in mysql_execute_command (thd=0x6acf620) at sql_parse.cc:2112
#17 0x000000000085d4c3 in sp_instr_stmt::exec_core (this=0x6c00a10, thd=0x6acf620, nextp=0x45576048) at sp_head.cc:2931
#18 0x000000000085de17 in sp_lex_keeper::reset_lex_and_exec_core (this=0x6c00a50, thd=0x6acf620, nextp=0x45576048,
    open_tables=false, instr=0x6c00a10) at sp_head.cc:2755
#19 0x000000000085e42d in sp_instr_stmt::execute (this=0x6c00a10, thd=0x6acf620, nextp=0x45576048) at sp_head.cc:2868
#20 0x00000000008605fe in sp_head::execute (this=0x6bfd358, thd=0x6acf620) at sp_head.cc:1250
#21 0x0000000000861cef in sp_head::execute_function (this=0x6bfd358, thd=0x6acf620, argp=0x2031676e655f3162, argcount=0,
    return_value_fld=0x6c0bf78) at sp_head.cc:1777
#22 0x00000000005b45b7 in Item_func_sp::execute_impl (this=0x6be3ea0, thd=0x6acf620) at item_func.cc:6144
#23 0x00000000005b462c in Item_func_sp::execute (this=0x6be3ea0) at item_func.cc:6078
#24 0x00000000005c7649 in Item_func_sp::val_int (this=0x6be3ea0) at item_func.h:1643
#25 0x00000000005b327c in Item_func_set_user_var::check (this=0x6be4c18, use_result_field=false) at item_func.cc:4325
#26 0x0000000000689bfd in set_var_user::check (this=0x6be5158, thd=0x6acf620) at set_var.cc:4315
#27 0x0000000000689c65 in sql_set_variables (thd=0x6acf620, var_list=0x6ad1958) at set_var.cc:4154
#28 0x00000000006786e7 in mysql_execute_command (thd=0x6acf620) at sql_parse.cc:3519
#29 0x000000000067cef0 in mysql_parse (thd=0x6acf620, inBuf=0x6be3b08 "SET @result1 = run_main_query()", length=31,
    found_semicolon=0x45577f30) at sql_parse.cc:5942
#30 0x000000000067e2c1 in dispatch_command (command=COM_QUERY, thd=0x6acf620,
    packet=0x6a64e41 "SET @result1 = run_main_query()", packet_length=31) at sql_parse.cc:1061
#31 0x000000000067f72a in do_command (thd=0x6acf620) at sql_parse.cc:743
#32 0x000000000066d0d7 in handle_one_connection (arg=0x6acf620) at sql_connect.cc:1158
#33 0x00000033a8c062f7 in start_thread () from /lib64/libpthread.so.0
#34 0x00000033a80d1b6d in clone () from /lib64/libc.so.6

Notes:

The attached test case contains a trigger on the table under update and transaction isolation level READ COMMITTED -- could not get rid of any of those.

Tried both Linux and Solaris, same result.

Could not reproduce on 5.1.

How to repeat:
Unpack the attached zip archive in your <server>/mysql-test folder, where mysql-test-run.pl and mysql-stress-test.pl sit.
It will create mysql-test/crash folder.
Run ./crash/crash.pl 

Usage: perl ./crash/crash.pl [options]

        --port=<num> (default 10000):
                 server port number
        --mysqltest=<path> (default ../client/mysqltest):
                 mysqltest binary location
        --mysqladmin=<path> (default ../client/mysqladmin):
                 mysqladmin binary location
        --start-server=<1|0> (default 1):
                 whether to start server or not
        --duration=<seconds> (default 300):
                 test duration
        --help
                 print this usage and exit

It starts the server using MTR (with all default options plus innodb), and runs 5-min stress test using mysql-stress-test.pl. It also pings the server using mysqladmin. 'mysqld is alive' is printed into stdout.

If the crash happens, the script should report 'ERROR: Server got lost!'. After that it might be slow killing children processes, but it is irrelevant.

If the test finishes on its own, the last thing mysql-stress-test reports is 'Got INT signal'.

Usually server crashes a few seconds after test start, although it is not 100%-reliable. If it does not happen in 5 minutes, please try to increase the test duration.
[29 Jul 2009 22:18] Elena Stepanova
test files, data and a wrapper for bug#46462

Attachment: crash.zip (application/zip, text), 15.47 KiB.

[30 Jul 2009 6:03] Sveta Smirnova
Thank you for the report.

Verified as described.
[9 Oct 2009 13:44] Konstantin Osipov
Sveta, could you please re-verify against 5.5 tree (mysql-next-mr).
Thank you.
[11 Oct 2009 9:19] Sveta Smirnova
Problem is not repeatable with current sources.