Bug #55084 Innodb crash and corruption after alter table
Submitted: 8 Jul 2010 14:33 Modified: 29 Apr 2011 21:08
Reporter: Teste Silva Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: InnoDB Plugin storage engine Severity:S1 (Critical)
Version:1.0.8, 5.1.49 OS:Linux (rhel 5.5 64bit)
Assigned to: Jimmy Yang CPU Architecture:Any
Tags: innodb, regression
Triage: Triaged: D1 (Critical) / R2 (Low) / E2 (Low)

[8 Jul 2010 14:33] Teste Silva
Description:
MySQL crashed after alter table with an assertion:

100707 18:26:35  InnoDB: Assertion failure in thread 1235339584 in file dict/dict0dict.c line 4780
InnoDB: Failing assertion: new_index
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
InnoDB: If you get repeated assertion failures or crashes, even
InnoDB: immediately after the mysqld startup, there may be
InnoDB: corruption in the InnoDB tablespace. Please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.1/en/forcing-recovery.html
InnoDB: about forcing recovery.
InnoDB: Thread 1256106304 stopped in file handler/ha_innodb.cc line 5527
100707 18:26:35 - 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.

key_buffer_size=536870912
read_buffer_size=2097152
max_used_connections=104
max_threads=1000
threads_connected=30
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 4630577 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

thd: 0x2aaafbe703b0
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
InnoDB: Thread 1243593024 stopped in file handler/ha_innodb.cc line 1538
stack_bottom = 0x49a1c100 thread_stack 0x40000
InnoDB: Thread 1249184064 stopped in file handler/ha_innodb.cc line 7177
/usr/sbin/mysqld(my_print_stacktrace+0x20) [0xa00d60]
/usr/sbin/mysqld(handle_segfault+0x36f) [0x5f7b8f]
/lib64/libpthread.so.0 [0x3ccf80eb10]
/usr/lib64/mysql/plugin/ha_innodb_plugin.so [0x2aaacee0e83e]
/usr/lib64/mysql/plugin/ha_innodb_plugin.so [0x2aaaceed8657]
/usr/lib64/mysql/plugin/ha_innodb_plugin.so [0x2aaacee5e7cc]
/usr/sbin/mysqld(mysql_alter_table(THD*, char*, char*, st_ha_create_information*, TABLE_LIST*, Alter_info*, unsigned int, st_order*, bool)+0x1bdc) [0x74dd4c]
/usr/sbin/mysqld(mysql_execute_command(THD*)+0x437a) [0x6043fa]
/usr/sbin/mysqld(mysql_parse(THD*, char const*, unsigned int, char const**)+0x33b) [0x60ac8b]
/usr/sbin/mysqld(dispatch_command(enum_server_command, THD*, char*, unsigned int)+0x1112) [0x5ff4e2]
/usr/sbin/mysqld(do_command(THD*)+0x110) [0x5fe3c0]
/usr/sbin/mysqld(handle_one_connection+0xcaf) [0x5fd77f]
/lib64/libpthread.so.0 [0x3ccf80673d]
/lib64/libc.so.6(clone+0x6d) [0x3ccf0d3d1d]
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort...
thd->query at 0x2aaafcc01ff0 is an invalid pointer
thd->thread_id=8629310
thd->killed=NOT_KILLED

After recovery is is not able to start anymore:

InnoDB: Apply batch completed
100707 18:27:44  InnoDB: Assertion failure in thread 47059265703184 in file dict/dict0dict.c line 4780
InnoDB: Failing assertion: new_index
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
InnoDB: If you get repeated assertion failures or crashes, even
InnoDB: immediately after the mysqld startup, there may be
InnoDB: corruption in the InnoDB tablespace. Please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.1/en/forcing-recovery.html
InnoDB: about forcing recovery.
100707 18:27:44 - 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.

key_buffer_size=536870912
read_buffer_size=2097152
max_used_connections=0
max_threads=1000
threads_connected=0
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 4630577 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

thd: 0x0
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = (nil) thread_stack 0x40000
/usr/sbin/mysqld(my_print_stacktrace+0x20) [0xa00d60]
/usr/sbin/mysqld(handle_segfault+0x36f) [0x5f7b8f]
/lib64/libpthread.so.0 [0x35bc80eb10]
/usr/lib64/mysql/plugin/ha_innodb_plugin.so [0x2aaacee0e83e]
/usr/lib64/mysql/plugin/ha_innodb_plugin.so [0x2aaaceed8e92]
/usr/lib64/mysql/plugin/ha_innodb_plugin.so [0x2aaacee897c6]
/usr/lib64/mysql/plugin/ha_innodb_plugin.so [0x2aaacef0987c]
/usr/lib64/mysql/plugin/ha_innodb_plugin.so [0x2aaacee5c213]
/usr/sbin/mysqld(ha_initialize_handlerton(st_plugin_int*)+0x32) [0x73ba02]
/usr/sbin/mysqld(plugin_init(int*, char**, int)+0xf81) [0x7e7f21]
/usr/sbin/mysqld [0x5f4886]
/usr/sbin/mysqld(main+0x20b) [0x5ece5b]
/lib64/libc.so.6(__libc_start_main+0xf4) [0x35bc01d994]
/usr/sbin/mysqld [0x4e6b59]

Innodb plugin 1.0.9 is unable to start either.

Workaround: builtin innodb is able to start after the crash.

Innodb plugin 1.0.9 is 

How to repeat:
Sorry, in a hosting shared environment it is impossible to isolate the query
[8 Jul 2010 16:51] Valeriy Kravchuk
Looks like this happens during new index creation and may be related to bug #44571 and other related bug reports. It would be nice to get a crashing statement.
[8 Aug 2010 23:00] Bugs System
No feedback was provided for this bug for over a month, so it is
being suspended automatically. If you are able to provide the
information that was originally requested, please do so and change
the status of the bug back to "Open".
[8 Sep 2010 18:30] martin fuxa
Assertion failure in thread ... in file dict/dict0dict.c line 4854; InnoDB: Failing assertion: new_index

Attachment: t2029.log (text/x-log), 6.48 KiB.

[8 Sep 2010 18:32] martin fuxa
Same problem, see attached log.

cat /etc/redhat-release
CentOS release 4.8 (Final)

uname --all
Linux freya 2.6.9-89.0.25.ELsmp #1 SMP Thu May 6 12:33:40 EDT 2010 x86_64 x86_64 x86_64 GNU/Linux

Server version 5.1.49 with bin-log
[10 Sep 2010 21:28] Sveta Smirnova
Thank you for the feedback.

From binary log is not clear which query failed: latest one is UPDATE while trace shows it should be ALTER. Please try to identify which query causes crash: probably you have core file or general log enabled?
[1 Oct 2010 23:13] martin fuxa
Havn't :(
But maybe it's related to #21395
query may be 
ALTER TABLE ... DROP INDEX ...
on foreign key.
I tried repeat this query on 5.1.49 and 5.1.50 at i686 - not same 64 bit - without crash.
[4 Nov 2010 1:57] Yasufumi Kinoshita
The following places may be able to cause race condition about table->foreign_list, because it seems not to obtain (or allow not to own) dict_sys->mutex.
And the race condition can make the ALTER TABLE work based on wrong judgement?

foreign_key_column_is_being_renamed():
===============
	/* check whether there are foreign keys at all */
	if (UT_LIST_GET_LEN(prebuilt->table->foreign_list) == 0
	    && UT_LIST_GET_LEN(prebuilt->table->referenced_list) == 0) {
===============

row_ins_index_entry():
===============
	if (foreign && UT_LIST_GET_FIRST(index->table->foreign_list)) {
		err = row_ins_check_foreign_constraints(index->table, index,
===============

row_ins_check_foreign_constraints():
===============
	foreign = UT_LIST_GET_FIRST(table->foreign_list);

	while (foreign) {
===============
[9 Nov 2010 3:52] Jimmy Yang
For assertion on ut_a(new_index), the only caller in dict0dict.c is by dict_table_replace_index_in_foreign_list() when we drop an index:

ha_innobase::final_drop_index()->row_merge_drop_index()->dict_table_replace_index_in_foreign_list().

Since for foreign key constraint, we must have index on referenced and referencing key columns, so when we drop an index involving the foreign keys, it must find an alternative. Otherwise, such index cannot be dropped. In dict_table_replace_index_in_foreign_list(), it calls dict_foreign_find_equiv_index() to find a alternative index to substitute the role of the dropping index.
The reason it asserts there must be such index is due to dict_foreign_find_equiv_index() had already been called in ha_innobase::prepare_drop_index():

ha_innobase::prepare_drop_index->dict_foreign_find_equiv_index()

if it cannot find an alternative index, it will return HA_ERR_DROP_INDEX_FK error.

And between ha_innobase::prepare_drop_index and ha_innobase::final_drop_index, the table is locked in MySQL level by metadata locks or LOCK_open. So there is no other "alter table" or rename can come in to change table definition.
As such, two consecutive calls to dict_foreign_find_equiv_index() must return identical result. If the first succeeds, the second in dict_table_replace_index_in_foreign_list() must succeed. So that is why the assertion ut_a(index) in dict_table_replace_index_in_foreign_list().

However, one thing to notice is that the check in ha_innobase::prepare_drop_index is only done if @@foreign_key_checks is on. If someone turn off @@foreign_key_checks, then the first call to dict_foreign_find_equiv_index() is skipped, and we could well trigger the error:

mysql> set foreign_key_checks=0;
Query OK, 0 rows affected (0.00 sec)

mysql>  select @@foreign_key_checks;
+----------------------+
| @@foreign_key_checks |
+----------------------+
|                    0 |
+----------------------+
1 row in set (0.00 sec)

mysql>  alter table child drop index idx5;
Query OK, 0 rows affected (3 min 29.10 sec)
Records: 0  Duplicates: 0  Warnings: 0

dict_table_replace_index_in_foreign_list (table=0x9015b28, index=0x902dfd0)
    at /home/jy/work/mysql5.5_7/mysql-trunk-innodb/storage/innobase/dict/dict0dict.c:4825
4825				ut_a(new_index);
(gdb) p new_index
$17 = (dict_index_t *) 0x0
(gdb) n
101108 18:47:06  InnoDB: Assertion failure in thread 2999352176 in file /home/jy/work/mysql5.5_7/mysql-trunk-innodb/storage/innobase/dict/dict0dict.c line 4825
InnoDB: Failing assertion: new_index
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
InnoDB: If you get repeated assertion failures or crashes, even
InnoDB: immediately after the mysqld startup, there may be
InnoDB: corruption in the InnoDB tablespace. Please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.1/en/forcing-recovery.html
InnoDB: about forcing recovery.

Program received signal SIGABRT, Aborted.
0x00333422 in __kernel_vsyscall ()
[9 Nov 2010 6:47] Jimmy Yang
we will first fix above assertion in the case of foreign_key_checks is set to 0. For  foreign_key_checks = 1, we still need to see if it repros. 

As mentioned above, dict_foreign_find_equiv_index( has been called twice, one in ha_innobase::prepare_drop_index and one in ha_innobase::final_drop_index. In between, MySQL has the dictionary locked, so all other DDLs (alter, drop/create etc.) will be blocked. So both dict_foreign_find_equiv_index() calls should give the same result.
[18 Nov 2010 16:11] Shannon Wade
This seems fixed in 5.1.51 as I can't recreate using reproducible case. on 5.1.49
[18 Nov 2010 16:26] Shannon Wade
nevermind my last comment, mistake on my part, it's present as tested in 5.1.52 pluggin, doesn't happen with built in innodb.
[15 Dec 2010 6:44] Jimmy Yang
Shannon, for the case you described (InnoDB: Failing assertion: new_index), it must not have the fix, since that assertion is changed along with the fix.

This fix is checked into mysql-5.1-innodb plugin on Nov 10th. So I am not sure if your server have the fix. Please check the innodb_plugin/ChangeLog:

2010-11-10      The InnoDB Team

        * dict/dict0dict.c, handler/handler0alter.cc, include/dict0dict.h
        row/row0merge.c:
        Fix Bug#55084 InnoDB crash and corruption after ALTER TABLE

In any case, the fix fixes following scenario:

mysql> CREATE TABLE parent (id INT NOT NULL,
    ->                      PRIMARY KEY (id)
    -> ) ENGINE=INNODB;
Query OK, 0 rows affected (0.13 sec)

mysql> CREATE TABLE child (id INT, parent_id INT,
    ->                     INDEX par_ind (parent_id),
    ->                     FOREIGN KEY (parent_id) REFERENCES parent(id)
    ->                       ON DELETE CASCADE
    -> ) ENGINE=INNODB;
Query OK, 0 rows affected (0.13 sec)

mysql> set foreign_key_checks=0;
Query OK, 0 rows affected (0.00 sec)

mysql> alter table child drop index par_ind;
=>assertion failure

In short, if user turns off "foreign_key_checks" (to 0) before drop an index needed by the foreign key constraint (and without an alternative index for the foreign key constraint. And then an assert (on new_index) will be triggered.

So above case is resolved. And John, please go ahead for the documentation.
[29 Apr 2011 21:08] John Russell
Added to 5.1.54 changelog:

Dropping an InnoDB index used by a foreign key constraint, while
foreign_key_checks was set to 0, could cause the server to crash with
an assertion. This operation now does not cause a crash. The foreign
key constraint can no longer be enforced once the associated index is
removed, so do not rely on it for referential integrity in this case.