牛骨文教育服务平台(让学习变的简单)

场景

某个打算用于slave新搭建的实例启动报错,启动过程中报告InnoDB数据页发生损坏。错误日志像下面这样:

150330 15:37:44 mysqld_safe Starting mysqld daemon with databases from /data/mysql/mytest_3306
2015-03-30 15:37:45 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use –explicit_defaults_for_timestamp server option (see documentation for more details).
2015-03-30 15:37:45 5884 [Warning] Using unique option prefix myisam_recover instead of myisam-recover-options is deprecated and will be removed in a future release. Please use the full name instead.
2015-03-30 15:37:45 5884 [Note] Plugin ‘FEDERATED’ is disabled.
2015-03-30 15:37:45 5884 [Note] InnoDB: Using atomics to ref count buffer pool pages
2015-03-30 15:37:45 5884 [Note] InnoDB: The InnoDB memory heap is disabled
2015-03-30 15:37:45 5884 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2015-03-30 15:37:45 5884 [Note] InnoDB: Memory barrier is not used
2015-03-30 15:37:45 5884 [Note] InnoDB: Compressed tables use zlib 1.2.3
2015-03-30 15:37:45 5884 [Note] InnoDB: Using Linux native AIO
2015-03-30 15:37:45 5884 [Note] InnoDB: Using CPU crc32 instructions
2015-03-30 15:37:45 5884 [Note] InnoDB: Initializing buffer pool, size = 2.0G
2015-03-30 15:37:46 5884 [Note] InnoDB: Completed initialization of buffer pool
2015-03-30 15:37:47 5884 [Note] InnoDB: Highest supported file format is Barr.
2015-03-30 15:37:48 5884 [Warning] InnoDB: Resizing redo log from 332768 to 216384 pages, LSN=2740249189
2015-03-30 15:37:48 5884 [Warning] InnoDB: Starting to delete and rewrite log files.
2015-03-30 15:37:48 5884 [Note] InnoDB: Setting log file ./ib_logfile101 size to 256 MB
InnoDB: Progress in MB: 100 200
2015-03-30 15:37:49 5884 [Note] InnoDB: Setting log file ./ib_logfile1 size to 256 MB
InnoDB: Progress in MB: 100 200
2015-03-30 15:37:50 5884 [Note] InnoDB: Renaming log file ./ib_logfile101 to ./ib_logfile0
2015-03-30 15:37:50 5884 [Warning] InnoDB: New log files created, LSN=2740249612
2015-03-30 15:37:50 5884 [Note] InnoDB: 128 rollback segment(s) are active.
2015-03-30 15:37:50 5884 [Note] InnoDB: Waiting for purge to start
2015-03-30 15:37:50 5884 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.6.21-rel69.0 started; log sequence number 2740249189
2015-03-30 15:37:50 5884 [Warning] No existing UUID has been found, so we assume that this is the first time that this server has been started. Generating a new UUID: ab27d3e4-d6af-11e4-8020-c81f66eeffa6.
150330 15:36:33 mysqld_safe Starting mysqld daemon with databases from /data/mysql/mytest_3306
2015-03-30 15:37:50 5884 [Warning] No existing UUID has been found, so we assume that this is the first time that this server has been started. Generating a new UUID: ab27d3e4-d6af-11e4-8020-c81f66eeffa6.
2015-03-30 15:37:50 5884 [Note] RSA private key file not found: /data/mysql/mytest_3306//private_key.pem. Some authentication plugins will not work.
2015-03-30 15:37:50 5884 [Note] RSA public key file not found: /data/mysql/mytest_3306//public_key.pem. Some authentication plugins will not work.
2015-03-30 15:37:50 5884 [Note] Server hostname (bind-address): ’10.x.x.x"; port: 3306
2015-03-30 15:37:50 5884 [Note] – ’10.x.x.x’ resolves to ’10.x.x.x";
2015-03-30 15:37:50 5884 [Note] Server socket created on IP: ’10.x.x.x’.
2015-03-30 15:37:50 7f4ce4d68700 InnoDB: Error: page 32769 log sequence number 2740254202
InnoDB: is in the future! Current system log sequence number 2740249622.
InnoDB: Your database may be corrupt or you may have copied the InnoDB
InnoDB: tablespace but not the InnoDB log files. See
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: for more information.
2015-03-30 15:37:50 5884 [Note] Event Scheduler: Loaded 0 events
2015-03-30 15:37:50 5884 [Note] /opt/Percona-Server-5.6.21-rel69.0-675.Linux.x86_64/bin/mysqld: ready for connections.
Version: ‘5.6.21-69.0-log’ socket: ‘/data/mysql/mytest_3306/mysql.sock’ port: 3306 Percona Server (GPL), Release 69.0, Revision 675
2015-03-30 15:37:58 7f4ce4d68700 InnoDB: Error: page 6327 log sequence number 2740254445
InnoDB: is in the future! Current system log sequence number 2740251356.
InnoDB: Your database may be corrupt or you may have copied the InnoDB
InnoDB: tablespace but not the InnoDB log files. See
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: for more information.

分析

正常情况下,新部署的实例是不太可能出现InnoDB数据页损坏的。经了解,这个实例是采用xtrabackup工具从master备份过来做恢复的。

细心的同学,通过观察上面的日志,应该能从中发现一些蛛丝马迹。有几个地方需要引起注意:

1、版本是Percona Server 5.6.21;
2、刚启动就把InnoDB的redo log给resize了;
3、刚启动就发现InnoDB的page LSN和redo log中的不匹配;

之所以提醒大家注意上面的三点,并且把版本信息放在了第一条,是因为从5.6版本开始,InnoDB如如果发现当前的redo log文件大小和预设配置的redo log大小不一致的话,就会自动将其删除重建。

写到这里,相信聪明的你应该已经想到什么了吧,没错,导致这个启动报错的原因是:从master上xtrabackup备份出来的innodb redo log大小和本地配置参数不一致,被删除重建,结果事务恢复失败,提示数据也损坏错误信息。

解决

修改slave本地配置文件,把下面几个InnoDB配置选项都修改成和在master上的一样,再次执行恢复启动即可。

innodb_data_file_path
innodb_log_file_size
innodb_log_files_in_group
innodb_file_per_table