Bug #34591 Innob crash in row_sel_store_mysql_rec() on multi-table delete
Submitted: 15 Feb 2008 11:56 Modified: 20 Jan 2010 14:00
Reporter: Philip Stoev Email Updates:
Status: Duplicate Impact on me:
None 
Category:MySQL Server: Optimizer Severity:S1 (Critical)
Version:6.0.4 OS:Any
Assigned to: Assigned Account
Tags: ICP, index_condition_pushdown, optimizer_switch, v6, v6
Triage: Triaged: D1 (Critical)

[15 Feb 2008 11:56] Philip Stoev
Description:
This crash may be related to bug #34590, since the same queries are used, however the stack trace is different:

#0  0x00110402 in __kernel_vsyscall ()
#1  0x00bdc617 in pthread_kill () from /lib/libpthread.so.0
#2  0x083f46fb in write_core (sig=11) at stacktrace.c:240
#3  0x0828dc05 in handle_segfault (sig=11) at mysqld.cc:2313
#4  <signal handler called>
#5  0x00ab68ac in memcpy () from /lib/libc.so.6
#6  0x085b0674 in row_sel_store_mysql_rec (mysql_rec=0xa300bb0 "Вc413", ' ' <repeats 36 times>, "1d-2ca8-102b-b04e-000c29c8314c\200", prebuilt=0xb6fdf868,
    rec=0xb6a5007e "3e2a4e1d-2ca8-102b-b04e-000c29c8314c\200", offsets=0xb26f2284, start_field_no=0, end_field_no=4) at row/row0sel.c:2566
#7  0x085b2b21 in row_search_for_mysql (buf=0xa300bb0 "Вc413", ' ' <repeats 36 times>, "1d-2ca8-102b-b04e-000c29c8314c\200", mode=2, prebuilt=0xb6fdf868,
    match_mode=1, direction=0) at row/row0sel.c:4170
#8  0x0855a3bf in ha_innobase::index_read (this=0xa3009d8, buf=0xa300bb0 "Вc413", ' ' <repeats 36 times>, "1d-2ca8-102b-b04e-000c29c8314c\200",
    key_ptr=0xa337368 "", key_len=37, find_flag=HA_READ_KEY_EXACT) at handler/ha_innodb.cc:4185
#9  0x0838dcd1 in handler::index_read_map (this=0xa3009d8, buf=0xa300bb0 "Вc413", ' ' <repeats 36 times>, "1d-2ca8-102b-b04e-000c29c8314c\200",
    key=0xa337368 "", keypart_map=1, find_flag=HA_READ_KEY_EXACT) at ../../sql/handler.h:1566
#10 0x0830976a in join_read_always_key (tab=0xa33bca4) at sql_select.cc:13964
#11 0x08300268 in sub_select (join=0xa3355b0, join_tab=0xa33bca4, end_of_records=false) at sql_select.cc:13280
#12 0x083000cb in evaluate_join_record (join=0xa3355b0, join_tab=0xa33baf0, error=<value optimized out>) at sql_select.cc:13505
#13 0x08300273 in sub_select (join=0xa3355b0, join_tab=0xa33baf0, end_of_records=false) at sql_select.cc:13281
#14 0x0830a939 in do_select (join=0xa3355b0, fields=0xa327fe8, table=0x0, procedure=0x0) at sql_select.cc:13038
#15 0x0830ff97 in JOIN::exec (this=0xa3355b0) at sql_select.cc:2713
#16 0x08310cac in mysql_select (thd=0xa294cb8, rref_pointer_array=0xa328058, tables=0xa328a08, wild_num=0, fields=@0xa327fe8, conds=0xa331480, og_num=0,
    order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=3493613184, result=0xa335570, unit=0xa327ccc, select_lex=0xa327f54)
    at sql_select.cc:2901
#17 0x0829adce in mysql_execute_command (thd=0xa294cb8) at sql_parse.cc:2834
#18 0x08405f17 in sp_instr_stmt::exec_core (this=0xa331570, thd=0xa294cb8, nextp=0xb26f3760) at sp_head.cc:2807
#19 0x0840618a in sp_lex_keeper::reset_lex_and_exec_core (this=0xa331598, thd=0xa294cb8, nextp=0xb26f3760, open_tables=false, instr=0xa331570)
    at sp_head.cc:2649
#20 0x0840cff2 in sp_instr_stmt::execute (this=0xa331570, thd=0xa294cb8, nextp=0xb26f3760) at sp_head.cc:2758
#21 0x08409d52 in sp_head::execute (this=0xa3274e8, thd=0xa294cb8) at sp_head.cc:1195
#22 0x0840a786 in sp_head::execute_procedure (this=0xa3274e8, thd=0xa294cb8, args=0xa295fbc) at sp_head.cc:1904
#23 0x0829d718 in mysql_execute_command (thd=0xa294cb8) at sql_parse.cc:3858
#24 0x0829ff5c in mysql_parse (thd=0xa294cb8, inBuf=0xa2f5300 "CALL delete_multi(@uuid)", length=24, found_semicolon=0xb26f42e4) at sql_parse.cc:5410
#25 0x082a0ed9 in dispatch_command (command=COM_QUERY, thd=0xa294cb8, packet=0xa2e26f9 "CALL delete_multi(@uuid)", packet_length=24) at sql_parse.cc:921
#26 0x082a1f73 in do_command (thd=0xa294cb8) at sql_parse.cc:697
#27 0x08291b1a in handle_one_connection (arg=0xa294cb8) at sql_connect.cc:1146
#28 0x00bd750b in start_thread () from /lib/libpthread.so.0
#29 0x00b18b2e in clone () from /lib/libc.so.6

How to repeat:
Test case will be provided shortly.
[15 Feb 2008 11:58] Philip Stoev
Schema dump for bug 34591

Attachment: bug34591_init.dump (application/octet-stream, text), 19.58 KiB.

[15 Feb 2008 11:58] Philip Stoev
Test case for bug 34591

Attachment: bug34591.test (application/octet-stream, text), 859 bytes.

[15 Feb 2008 12:04] Philip Stoev
To repeat:

1. Please place bug34591_init.dump in mysql-test and bug34591.test in mysql-test/t

2. Start a fresh mysql server:

$ perl mysql-test-run.pl --start-and-exit --skip-ndb --mysqld=--innodb

3. Load database schema:

$ ../client/mysql -uroot --socket=var/tmp/master.sock -f test < bug34591_init.dump

4. Execute test case:

$ perl mysql-test-run.pl --extern --socket=var/tmp/master.sock --user=root bug34591

I am sorry for not being able to reduce the test case further -- bug34591_init.dump contains some unrelated database objects. Please let me know if a better test case is required and I will work on it.
[15 Feb 2008 14:07] Heikki Tuuri
The probable reason is that the multi-table delete in 6.0.4 misuses table handles. For example, uses a table handle without first calling ::external_lock() on it.
[4 Mar 2008 17:33] Heikki Tuuri
Calvin, when you build 6.0, please look at this crash. MySQL may be calling handler functions in a wrong order.
--Heikki
[2 Jul 2008 14:43] Philip Stoev
This was observed on a simple single-table delete

DELETE K FROM `A` AS K WHERE K . int_key < 222

where int_key is an integer column with a key on it.

Backtrace is:

#0  0x00110416 in __kernel_vsyscall ()
#1  0x00581c78 in pthread_kill () from /lib/libpthread.so.0
#2  0x085b0dc4 in my_write_core (sig=11) at stacktrace.c:307
#3  0x08213e88 in handle_segfault (sig=11) at mysqld.cc:2638
#4  <signal handler called>
#5  0x0854c653 in row_sel_store_mysql_rec (mysql_rec=0xab5ea00 "Ъ\006", prebuilt=0xadc63068, rec=0xad6c80a6 "\200", offsets=0xa89f9de8, start_field_no=0,
    end_field_no=3) at row/row0sel.c:2463
#6  0x0854eae9 in row_search_for_mysql (buf=0xab5ea00 "Ъ\006", mode=1, prebuilt=0xadc63068, match_mode=0, direction=0) at row/row0sel.c:4191
#7  0x084cc67a in ha_innobase::index_read (this=0xab5e868, buf=0xab5ea00 "Ъ\006", key_ptr=0xab818f8 "\001", key_len=5, find_flag=HA_READ_AFTER_KEY)
    at handler/ha_innodb.cc:4242
#8  0x0830bd93 in handler::index_read_map (this=0xab5e868, buf=0xab5ea00 "Ъ\006", key=0xab818f8 "\001", keypart_map=1, find_flag=HA_READ_AFTER_KEY)
    at ../../sql/handler.h:1664
#9  0x0830436f in handler::read_range_first (this=0xab5e868, start_key=0xab5e8f0, end_key=0xab5e900, eq_range_arg=false, sorted=false) at handler.cc:4907
#10 0x084c7fdf in ha_innobase::read_range_first (this=0xab5e868, start_key=0xab5e8f0, end_key=0xab5e900, eq_range_arg=<value optimized out>,
    sorted=<value optimized out>) at handler/ha_innodb.cc:8394
#11 0x0830337d in handler::multi_range_read_next (this=0xab5e868, range_info=0xa89fa58c) at handler.cc:4262
#12 0x08304d40 in DsMrr_impl::dsmrr_next (this=0xab5e9dc, h=0xab5e868, range_info=0xa89fa58c) at handler.cc:4464
#13 0x084c80af in ha_innobase::multi_range_read_next (this=0xab5e868, range_info=0xa89fa58c) at handler/ha_innodb.cc:8327
#14 0x082ea15a in QUICK_RANGE_SELECT::get_next (this=0xab5dd48) at opt_range.cc:8518
#15 0x082fe857 in rr_quick (info=0xab649f4) at records.cc:298
#16 0x0826e88c in join_init_read_record (tab=0xab649b0) at sql_select.cc:14481
#17 0x08281615 in sub_select (join=0xab5ac80, join_tab=0xab649b0, end_of_records=false) at sql_select.cc:13636
#18 0x0828b5b9 in do_select (join=0xab5ac80, fields=0xab4e31c, table=0x0, procedure=0x0) at sql_select.cc:13387
#19 0x0828d761 in JOIN::exec (this=0xab5ac80) at sql_select.cc:2811
#20 0x0828e1fa in mysql_select (thd=0xab4cea8, rref_pointer_array=0xab4e38c, tables=0xab63e98, wild_num=0, fields=@0xab4e31c, conds=0xab643e0, og_num=0,
    order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=3489942144, result=0xab64530, unit=0xab4dff8, select_lex=0xab4e288)
    at sql_select.cc:3001
#21 0x0822350f in mysql_execute_command (thd=0xab4cea8) at sql_parse.cc:3127
#22 0x0822a02e in mysql_parse (thd=0xab4cea8, inBuf=0xab63730 "DELETE K FROM `A` AS K WHERE K . int_key < 222", length=46, found_semicolon=0xa89fb314)
    at sql_parse.cc:5811
#23 0x0822a921 in dispatch_command (command=COM_QUERY, thd=0xab4cea8, packet=0xab5f711 "DELETE K FROM `A` AS K WHERE K . int_key < 222  ", packet_length=48)
    at sql_parse.cc:1051
#24 0x0822ba49 in do_command (thd=0xab4cea8) at sql_parse.cc:724
#25 0x0821bef0 in handle_one_connection (arg=0xab4cea8) at sql_connect.cc:1153
#26 0x0057d32f in start_thread () from /lib/libpthread.so.0
#27 0x0049a27e in clone () from /lib/libc.so.6

2459                    ptr = dest + len;
2460
2461                    for (;;) {
2462                            ptr--;
2463                            *ptr = *data; <<<< HERE
2464                            if (ptr == dest) {
2465                                    break;
2466                            }
2467                            data++;

(gdb) print *data
$3 = 204 'л'
(gdb) print data
$4 = (unsigned char *) 0xb5c7e506 'л' <repeats 200 times>...
[8 Jul 2008 19:02] Sergey Petrunya
The crash doesn't happen if I turn off DS-MRR and Index Condition Pushdown before running the test case.

(The commands to do so are:
 set engine_condition_pushdown=off;
 set optimizer_use_mrr='disable';
)
[8 Jul 2008 19:04] Sergey Petrunya
... which probably means the problem is on MySQL side, not on InnoDB's. 

Changing category and re-assigning accordingly.
[26 Jun 2009 11:11] Sanjay Manwani
Marking as duplicate to 45029
[7 Jul 2009 4:43] Amit Saha
Closing it as duplicate of 45029
[4 Dec 2009 7:10] Sveta Smirnova
This bug is not repeatable for me with today mysql-6.0-codebase.

Philip, Timothy, please check on your side.
[4 Dec 2009 7:12] Philip Stoev
This bug requires innodb mrr ,which is disabled in the current trees, that is why you can not reproduce it.
[20 Jan 2010 14:00] Olav Sandstå
The crash reported in this bug is the same as several other bug reports
caused by two memory corruptions in Index Condition Pushdown for InnoDB. These bugs are fixed by the patches committed for Bug#43360 and Bug#36981. 

I have verified that the initial test case in this bug report still
fails if the fixes for Bug#43360 and Bug#36981 are not applied but runs correctly after applying the patches.

The test case in this bug is almost identical to the test case committed for
Bug#35080 so I will not add this as a separate test case.

Closing this bug as duplicate of Bug#43360 and Bug#36981.