最近要将使用xtrabackup备份的多台MySQL Server的数据还原到另外一台MySQL服务器上并使用不同的端口启动多个实例来作为review环境。实用程序执行自动还原的过程中有几个数据库实例启动失败。检查数据目录中的错误日志,发现如下启动错误:
2015-02-02 12:31:36 27876 [Note] Plugin 'FEDERATED' is disabled. 2015-02-02 12:31:36 27876 [Note] InnoDB: The InnoDB memory heap is disabled 2015-02-02 12:31:36 27876 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins 2015-02-02 12:31:36 27876 [Note] InnoDB: Compressed tables use zlib 1.2.3 2015-02-02 12:31:36 27876 [Note] InnoDB: Using CPU crc32 instructions 2015-02-02 12:31:36 27876 [Note] InnoDB: Initializing buffer pool, size = 500.0M 2015-02-02 12:31:36 27876 [Note] InnoDB: Completed initialization of buffer pool 2015-02-02 12:31:36 27876 [Note] InnoDB: Highest supported file format is Barracuda. 2015-02-02 12:31:36 27876 [Note] InnoDB: The log sequence numbers 13637542590703 and 13637542590703 in ibdata files do not match the log sequence number 13637542595176 in the ib_logfiles! 2015-02-02 12:31:36 27876 [Note] InnoDB: Database was not shutdown normally! 2015-02-02 12:31:36 27876 [Note] InnoDB: Starting crash recovery. 2015-02-02 12:31:36 27876 [Note] InnoDB: Reading tablespace information from the .ibd files... 2015-02-02 12:31:37 27876 [Note] InnoDB: Restoring possible half-written data pages 2015-02-02 12:31:37 27876 [Note] InnoDB: from the doublewrite buffer... 2015-02-02 12:31:37 2aeb2d96a590 InnoDB: Error: page 7 log sequence number 36755345241838 InnoDB: is in the future! Current system log sequence number 13637542595176. 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-02-02 12:31:37 2aeb2d96a590 InnoDB: Error: page 1 log sequence number 35468208055287 InnoDB: is in the future! Current system log sequence number 13637542595176. 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. ……
是说ibdata文件中的日志序列号与ib_logfiles文件中的日志序列号不一致,启动崩溃恢复过程,从.ibd文件读表空间信息,从双写缓冲恢复数据页。但发现页中的日志序列号超前于当前系统日志序列号。提示数据库可能损毁。或者备份时只备了表空间没备日志文件。因此,推测错误可能发生在两个环节:一备份文件本身损坏了;二备份文件本身没有问题,在应用日志的时候出现了问题。
先从简单的情况验证
手动拉取前一天的xtrabackup全备文件一步步执行还原过程,在应用日志阶段。发现如下报错:
…… 150202 12:36:35 innobackupex: Connecting to MySQL server with DSN 'dbi:mysql:;mysql_read_default_file=/etc/my.cnf;mysql_read_default_group=xtrabackup' as 'usvr_serveradmin' (using password: YES). 150202 12:36:35 innobackupex: Connected to MySQL server Connected successfully Can't call method "disconnect" on an undefined value at /usr/bin/innobackupex line 1482. ……
正常情况下当输出complete ok!所以断定是这里出问题了。所有机器都是使用同样的还原程序进行还原的,为什么只有某几台发生这样的问题?经查看,这些机器是安装的MySQL版本为5.6.21,xtrabackup版本为2.2.24。而最终要还原到的MySQL Server实例本身是5.6.12的,xtrabackup版本为2.1.3。
使用xtrabackup2.2.24替换2.1.3后重新对全备文件应用日志,发现可以成功执行。所以最终问题定位到了这里。也即,使用高版本的xtrabackup备份的全备文件,在使用低版本的xtrabackup应用日志时会出问题。(与MySQL Server本身的版本木有必然联系)
但接下来问题又来了,其余的一些机器中也存在少数几台MySQL5.6.21的,xtrabackup版本为2.2.24的。为什么还原成功??观察这几台机器的数据库,发现数据库均为空,这样也就不存在对全备应用日志的情况。因而全备还原会成功。
综上:使用高版本的xtrabackup备的全备在使用低版本的xtrabackup应用日志时存在问题,这一点需注意。