MySQL5.5.32遇到的Bug #69623

昨天开发人员用Vim打开了一个超大的DUMP文件等了很久Vim都是一直在打开状态,后来短信报警发现MySQL后台进程没有了(-_-这里鄙视一下那个开发)..在mysqld_safe启动不起来了.查看error.log日志发现也没有crash的信息很奇怪在一次重启报如下错误

140211 14:39:09 [Note] /usr/local/mysql/bin/mysqld: Shutdown complete

140211 14:39:09 mysqld_safe mysqld from pid file /dev/shm/mysql.pid ended
140211 14:41:36 mysqld_safe Starting mysqld daemon with databases from /mysql/data
140211 14:41:36 [Note] Plugin 'FEDERATED' is disabled.
140211 14:41:36 InnoDB: The InnoDB memory heap is disabled
140211 14:41:36 InnoDB: Mutexes and rw_locks use GCC atomic builtins
140211 14:41:36 InnoDB: Compressed tables use zlib 1.2.3
140211 14:41:36 InnoDB: Using Linux native AIO
140211 14:41:36 InnoDB: Initializing buffer pool, size = 44.0G
140211 14:41:38 InnoDB: Completed initialization of buffer pool
InnoDB: Error: checksum mismatch in data file /mysql/data/ibdata2
140211 14:41:38 InnoDB: Could not open or create data files.
140211 14:41:38 InnoDB: If you tried to add new data files, and it failed here,
140211 14:41:38 InnoDB: you should now edit innodb_data_file_path in my.cnf back
140211 14:41:38 InnoDB: to what it was, and remove the new ibdata files InnoDB created
140211 14:41:38 InnoDB: in this failed attempt. InnoDB only wrote those files full of
140211 14:41:38 InnoDB: zeros, but did not yet use them in any way. But be careful: do not
140211 14:41:38 InnoDB: remove old data files which contain your precious data!
140211 14:41:38 [ERROR] Plugin 'InnoDB' init function returned error.
140211 14:41:38 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
140211 14:41:38 [ERROR] Unknown/unsupported storage engine: InnoDB
140211 14:41:38 [ERROR] Aborting

140211 14:41:38 [Note] /usr/local/mysql/bin/mysqld: Shutdown complete

后来通过innochecksum -d /mysql/data/ibdata2也没有发现异常,后来通过修改my.cnf添加innodb_force_recovery起来了,需要注意的是如果设置innodb_force_recovery同时又设置innodb_purge_threads需要将此参数关闭,否则日志会不管报如下信息
140211 14:21:23  InnoDB: Waiting for the background threads to start
140211 14:21:24  InnoDB: Waiting for the background threads to start
140211 14:21:25  InnoDB: Waiting for the background threads to start
140211 14:21:26  InnoDB: Waiting for the background threads to start
140211 14:21:27  InnoDB: Waiting for the background threads to start
140211 14:21:28  InnoDB: Waiting for the background threads to start
140211 14:21:29  InnoDB: Waiting for the background threads to start
.....
.....

用innodb_force_recovery启动之后日志
InnoDB: mysqld and edit my.cnf so that newraw is replaced
InnoDB: with raw, and innodb_force_... is removed.
140211 15:47:31 [Warning] Slave SQL: Could not execute Update_rows event on table xxxxxx.xxxxxx; Got error -1 from storage engine, Error_code: 1030; handler error No Error!; the event's master log mysql-bin.002693, end_log_pos 28107749, Error_code: 1030
InnoDB: A new raw disk partition was initialized or
InnoDB: innodb_force_recovery is on: we do not allow
InnoDB: database modifications by the user. Shut down
InnoDB: mysqld and edit my.cnf so that newraw is replaced
InnoDB: with raw, and innodb_force_... is removed.
140211 15:47:31 [Warning] Slave SQL: Could not execute Write_rows event on table xxxxx.xxxxx; Got error -1 from storage engine, Error_code: 1030; handler error No Error!; the event's master log mysql-bin.002693, end_log_pos 28107921, Error_code: 1030
InnoDB: A new raw disk partition was initialized or
InnoDB: innodb_force_recovery is on: we do not allow
InnoDB: database modifications by the user. Shut down
InnoDB: mysqld and edit my.cnf so that newraw is replaced
InnoDB: with raw, and innodb_force_... is removed.
140211 15:47:31 [Warning] Slave SQL: Could not execute Write_rows event on table xxxxxx.xxxxx; Got error -1 from storage engine, Error_code: 1030; handler error No Error!; the event's master log mysql-bin.002693, end_log_pos 28108075, Error_code: 1030
InnoDB: A new raw disk partition was initialized or
InnoDB: innodb_force_recovery is on: we do not allow
InnoDB: database modifications by the user. Shut down
InnoDB: mysqld and edit my.cnf so that newraw is replaced
InnoDB: with raw, and innodb_force_... is removed.
140211 15:47:31 [Warning] Slave SQL: Could not execute Write_rows event on table xxxxx.xxxxx; Got error -1 from storage engine, Error_code: 1030; handler error No Error!; the event's master log mysql-bin.002693, end_log_pos 28109717, Error_code: 1030
InnoDB: A new raw disk partition was initialized or
InnoDB: innodb_force_recovery is on: we do not allow
InnoDB: database modifications by the user. Shut down
InnoDB: mysqld and edit my.cnf so that newraw is replaced
InnoDB: with raw, and innodb_force_... is removed.
InnoDB: A new raw disk partition was initialized or
InnoDB: innodb_force_recovery is on: we do not allow
InnoDB: database modifications by the user. Shut down
InnoDB: mysqld and edit my.cnf so that newraw is replaced
InnoDB: with raw, and innodb_force_... is removed.
InnoDB: A new raw disk partition was initialized or
InnoDB: innodb_force_recovery is on: we do not allow
InnoDB: database modifications by the user. Shut down
InnoDB: mysqld and edit my.cnf so that newraw is replaced
InnoDB: with raw, and innodb_force_... is removed.
InnoDB: A new raw disk partition was initialized or
InnoDB: innodb_force_recovery is on: we do not allow
.....
.....
.....

经查看应该是MySQL Bug原文如下:
[30 Jun 2013 11:25] Shane Bester
Description:
5.5.32 fails to open the second tablespace:
InnoDB: Error: checksum mismatch in data file .\ib2
InnoDB: Could not open or create data files.

5.6.12 fails like this:

[ERROR] InnoDB: Space id in fsp header 65592,but in the page header 0
[ERROR] InnoDB: checksum mismatch in data file .\ib2
[ERROR] InnoDB: Could not open or create the system tablespace. If you tried to add new data files to the system tablespace, and it failed here, you should now edit innodb_data_file_path in my.cnf back to what it was, and remove the new ibdata files InnoDB created in this failed attempt. InnoDB only wrote those files full of zeros, but did not yet use them in any way. But
be careful: do not remove old data files which contain your precious data!

This is a major problem, many folks will be unable to upgrade at all.

How to repeat:
start 5.5.32 or 5.6.12 with new tablespace, e.g.

--innodb-data-file-path="ib1:10M;ib2:20M:autoextend"

insert data and restart instance:

------
drop table if exists t1;
create table t1(a int primary key,b blob,c date,key(a,b(10),c))engine=innodb;
replace into t1 values (1,'test',now()),(2,'test',now()),
(3,'test',now()),(4,'test',now());
set @a:=5;
replace into t1(a,b,c) select @a:=@a+1,rand(),now() 
from t1 a,t1 b,t1 c,t1 d,t1 e,t1 f,t1 g,t1 h,t1 i, t1 j;
-----
[30 Jun 2013 11:38] Shane Bester
also:
[5 Jul 2013 16:24] Bugs System
Added a changelog entry for 5.5.33, 5.6.13, 5.7.2:

"InnoDB would fail to open a tablespace that has multiple data files."

Thank you for the bug report.
[11 Jul 2013 5:53] Erlend Dahl
bug#69573 was marked as a duplicate.
[15 Jul 2013 19:04] James Day
Note that you can receive this error message:

[ERROR] InnoDB: Space id in fsp header 65592(or any other number),but in the page header 0

even for 5.6.11 and perhaps earlier versions if you have more than one file for the InnoDB shared tablespace.

If this is reported for a second or later file in the shared tablespace it is a false alarm. These files are expected to have a 0 for the space id in their header. The problem is an insufficiently selective check for damage.
[15 Jul 2013 19:24] James Day
If you do receive that error message in an earlier version you should not upgrade to 5.6.12 or 5.5.32, because the extra error checking will prevent the server from starting after the upgrade. Instead, wait for 5.6.13 or 5.5.33 and upgrade to one of those.

If you do upgrade to the affected versions and the server no longer starts, either upgrade to a later version or downgrade to 5.6.11 or 5.5.31. The unnecessary error message causes no damage and no additional corrective action is required.

James Day, MySQL Senior Principal Support Engineer, Oracle
[16 Jul 2013 12:03] Bugs System
The following limitation has been documented in the 5.5.32 and 5.6.12 release notes:

""InnoDB" may fail to open a tablespace that has multiple data files due to
newly introduced corruption checking functionality. It is recommended that
you do not upgrade to this version if you have more than one file for your
shared "InnoDB" tablespace. If you have upgraded to an affected version
and the server no longer starts, you can upgrade to a later version when
it becomes available or downgrade to an earlier version."

网址:原因还待查.当时因为开发打开一个20G左右的DUMP文件导致MySQL挂错误日志中也没有任何当时crash的信息.(-_-足足20G你要截取DUMP中的内容告诉我啊..还好不是主库只是一个内部使用的小库.我去.)总之还是尽快升级到新版本要紧.-_-