Bug #60042 Crash in ha_innobase::open
Submitted: 9 Feb 2011 9:50 Modified: 5 Jan 2012 0:19
Reporter: Roel Van de Paar Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: InnoDB storage engine Severity:S1 (Critical)
Version:5.6.2-m5 (mysql-next-mr-opt-backporting) OS:Any
Assigned to: Jimmy Yang CPU Architecture:Any

[9 Feb 2011 9:50] Roel Van de Paar
Description:
(gdb) bt
#0  0x0000000000988c2d in ha_innobase::open (this=0x7f7e1404f9b0,
    name=0x7f7e0c054978 "./test/@0I@00b7D@002c@0016@002c@0I@4vO@0J@00basO@0J@203a@0018K@0J@2030w@0J@00bf@0I@201e@0028n@0I@2122X@0J@2021@0J@00
a2@003d@0J@00a2@0I@201c@0011V9@002a8", mode=2, test_if_locked=2)
    at /mysql/mysql-next-mr-opt-backporting/storage/innobase/handler/ha_innodb.cc:4023
#1  0x000000000075a82a in handler::ha_open (this=0x7f7e1404f9b0, table_arg=0x7f7e1404f070,
    name=0x7f7e0c054978 "./test/@0I@00b7D@002c@0016@002c@0I@4vO@0J@00basO@0J@203a@0018K@0J@2030w@0J@00bf@0I@201e@0028n@0I@2122X@0J@2021@0J@00
a2@003d@0J@00a2@0I@201c@0011V9@002a8", mode=2, test_if_locked=2) at /mysql/mysql-next-mr-opt-backporting/sql/handler.cc:2160
#2  0x00000000006a7055 in open_table_from_share (thd=0x3374290, share=0x7f7e0c0545c0,
    alias=0x7f7e1403ca68 "·D,\026,ÂzOúsOÃ>\030KÃ%wÿÂ"(nÂTXÃ╬â=âÂ"\021V9*8", db_stat=39, prgflag=44,
    ha_open_flags=0, outparam=0x7f7e1404f070, is_create_table=false) at /mysql/mysql-next-mr-opt-backporting/sql/table.cc:2020
#3  0x00000000005a6f99 in open_table (thd=0x3374290, table_list=0x7f7e1404b5f8, mem_root=0x7f7e4275f170, ot_ctx=0x7f7e4275f1b0)
    at /mysql/mysql-next-mr-opt-backporting/sql/sql_base.cc:3039
#4  0x00000000005a9264 in open_and_process_table (thd=0x3374290, lex=0x3375ef0, tables=0x7f7e1404b5f8, counter=0x7f7e4275f2dc, flags=1026,
    prelocking_strategy=0x7f7e4275f2e0, has_prelocking_list=false, ot_ctx=0x7f7e4275f1b0, new_frm_mem=0x7f7e4275f170)
    at /mysql/mysql-next-mr-opt-backporting/sql/sql_base.cc:4374
#5  0x00000000005a9fb7 in open_tables (thd=0x3374290, start=0x7f7e4275f290, counter=0x7f7e4275f2dc, flags=1026,
    prelocking_strategy=0x7f7e4275f2e0) at /mysql/mysql-next-mr-opt-backporting/sql/sql_base.cc:4814
#6  0x00000000005ab0cb in open_normal_and_derived_tables (thd=0x3374290, tables=0x7f7e1404b5f8, flags=1026)
    at /mysql/mysql-next-mr-opt-backporting/sql/sql_base.cc:5475
#7  0x0000000000662f54 in get_all_tables (thd=0x3374290, tables=0x7f7e14005dc8, cond=0x7f7e14006780)
    at /mysql/mysql-next-mr-opt-backporting/sql/sql_show.cc:3643
#8  0x000000000067085c in get_schema_tables_result (join=0x7f7e14009088, executed_place=PROCESSED_BY_JOIN_EXEC)
    at /mysql/mysql-next-mr-opt-backporting/sql/sql_show.cc:6741
#9  0x0000000000620294 in JOIN::exec (this=0x7f7e14009088) at /mysql/mysql-next-mr-opt-backporting/sql/sql_select.cc:2836
#10 0x0000000000622948 in mysql_select (thd=0x3374290, rref_pointer_array=0x33767c0, tables=0x7f7e14005dc8, wild_num=0, fields=...,
    conds=0x7f7e14006780, og_num=4, order=0x7f7e14007d98, group=0x7f7e140069c8, having=0x0, proc_param=0x0, select_options=2684619520,
    result=0x7f7e14009068, unit=0x3375fa0, select_lex=0x33765d8) at /mysql/mysql-next-mr-opt-backporting/sql/sql_select.cc:3554
#11 0x0000000000619291 in handle_select (thd=0x3374290, lex=0x3375ef0, result=0x7f7e14009068, setup_tables_done_option=0)
    at /mysql/mysql-next-mr-opt-backporting/sql/sql_select.cc:323
#12 0x00000000005fb9e4 in execute_sqlcom_select (thd=0x3374290, all_tables=0x7f7e14005dc8)
    at /mysql/mysql-next-mr-opt-backporting/sql/sql_parse.cc:4513
#13 0x00000000005f4821 in mysql_execute_command (thd=0x3374290) at /mysql/mysql-next-mr-opt-backporting/sql/sql_parse.cc:2096
#14 0x00000000005fdb41 in mysql_parse (thd=0x3374290,
    rawbuf=0x7f7e14004c70 "select `table_schema`,`table_name`,`index_name`,`index_type`,`sub_part`,group_concat(`statistics`.`column_name` or
der by `seq_in_index`) as `col_list` from `information_schema`.`statistics` where `tab"..., length=343, parser_state=0x7f7e42761610)
    at /mysql/mysql-next-mr-opt-backporting/sql/sql_parse.cc:5550
#15 0x00000000005f2130 in dispatch_command (command=COM_QUERY, thd=0x3374290,
    packet=0x3377391 "select `table_schema`,`table_name`,`index_name`,`index_type`,`sub_part`,group_concat(`statistics`.`column_name` order b
y `seq_in_index`) as `col_list` from `information_schema`.`statistics` where `tab"..., packet_length=343)
    at /mysql/mysql-next-mr-opt-backporting/sql/sql_parse.cc:1078
#16 0x00000000005f1462 in do_command (thd=0x3374290) at /mysql/mysql-next-mr-opt-backporting/sql/sql_parse.cc:815
#17 0x00000000006cfcfe in do_handle_one_connection (thd_arg=0x3374290) at /mysql/mysql-next-mr-opt-backporting/sql/sql_connect.cc:748
#18 0x00000000006cf88f in handle_one_connection (arg=0x3374290) at /mysql/mysql-next-mr-opt-backporting/sql/sql_connect.cc:684
#19 0x00000032c2406d5b in start_thread () from /lib64/libpthread-2.12.90.so
#20 0x00000032c1ce4a7d in clone () from /lib64/libc-2.12.90.so

How to repeat:
Blobs + odd characters
[9 Feb 2011 10:08] Roel Van de Paar
mysql> show tables;
ERROR 2006 (HY000): MySQL server has gone away

Same crash.

So must be some corruption that happened. This was after bug #60038.
[10 Feb 2011 10:51] Jimmy Yang
A previous crash has left the table definition in MySQL and InnoDB inconsistent:

<Roel> Version: '5.6.2-m5-debug'  socket: '/mysql2/mysql-5.6.2-m5-linux-x86_64-debug/socket-5621.sock'  port: 5621  Source distribution
<Roel> 110209 21:00:13 [ERROR] Table ./test/@0I@00b7D@002c@0016@002c@0I@4vO@0J@00basO@0J@203a@0018K@0J@2030w@0J@00bf@0I@201e@0028n@0I@2122X@0J@2021@
<Roel> 0J@00a2@003d@0J@00a2@0I@201c@0011V9@002a8 has a primary key in InnoDB data dictionary, but not in MySQL!
<Roel> 110209 21:00:13 - mysqld got signal 11 ;

So MySQL do not have any index defined, but InnoDB has a primary index "idx1".

<Roel> (gdb) p table->key_info
<Roel> $3 = (KEY *) 0x0
<Roel> (gdb) p table->s->keys
<Roel> $9 = 0

After printing the message, when we reference table->key_info[0].key_length, it will trigger sig 11 since table->key_info is NULL.

Fix will be check null for table->key_info before it continue.
[15 Feb 2011 13:07] Jimmy Yang
As above analysis, this can be repro-ed using a debugger:

mysql> create table aa(a int not NULL) engine = innodb;
Query OK, 0 rows affected (0.13 sec)

Put breakpoint at ha_innobase::add_index and let following create index finishing  ha_innobase::add_index(). Before it return to MySQL server, kill the server
Breakpoint 3, ha_innobase::add_index (this=0x90be940, table=0x90be268, 
    key_info=0x9093588, num_of_keys=1)
    at /home/jy/work2/mysql-trunk-innodb3/storage/innobase/handler/handler0alter.cc:1034
1034		DBUG_RETURN(error);
(gdb) p error
$2 = 0
(gdb) kill
Kill the program being debugged? (y or n) y

mysql> create unique index idx on aa(a);
ERROR 2013 (HY000): Lost connection to MySQL server during query

This is to create a primary index. But it is successful in InnoDB but failed to do so in MySQL server, and we had a mismatch.

Reboot the server, and access the table:

mysql> select * from aa;
 
Program received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0xb1c28b70 (LWP 32249)]
0x08594f5e in ha_innobase::open (this=0x903f9f0, name=0x8fff5c0 "./test/aa", 
    mode=2, test_if_locked=2)
    at /home/jy/work2/mysql-trunk-innodb3/storage/innobase/handler/ha_innodb.cc:4057
4057				ref_length = table->key_info[0].key_length;
(gdb) c
Continuing.
110215  5:03:36 - mysqld got signal 11 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
We will try our best to scrape up some info that will hopefully help diagnose
the problem, but since we have already crashed, something is definitely wrong
and this may fail.
...
stack_bottom = 0xb1c282f8 thread_stack 0x30000
/home/jy/work2/mysql-trunk-innodb3/bld/sql/mysqld(my_print_stacktrace+0x32)[0x84f30b9]
/home/jy/work2/mysql-trunk-innodb3/bld/sql/mysqld(handle_segfault+0x2b1)[0x818434d]
[0x294400]
/home/jy/work2/mysql-trunk-innodb3/bld/sql/mysqld(_ZN7handler7ha_openEP5TABLEPKcii+0x114)[0x8356c10]
/home/jy/work2/mysql-trunk-innodb3/bld/sql/mysqld(_Z21open_table_from_shareP3THDP11TABLE_SHAREPKcjjjP5TABLEb+0xa55)[0x82ad693]
/home/jy/work2/mysql-trunk-innodb3/bld/sql/mysqld(_Z10open_tableP3THDP10TABLE_LISTP11st_mem_rootP18Open_table_context+0x101e)[0x81bb6ab]
/home/jy/work2/mysql-trunk-innodb3/bld/sql/mysqld[0x81bd768]
[5 Jan 2012 0:19] John Russell
Added to 5.6.3 changelog:

If the MySQL Server crashed immediately after creating an InnoDB
table, attempting to access the table after restart could cause
another crash. The issue could occur if the server halted after
InnoDB created the primary index for the table, but before the index
definition was recorded in the MySQL metadata.