MySQL断电恢复的一点简单分析

今天有个网友问我一个MySQL的恢复问题。提供的截图如下。

对于这个问题，在一些断电的场景下还是可能出现的。我首先是要确认是否为线上业务还是测试环境，线上业务来说这个影响还是很大的。如果数据库无法启动，首要任务还是把数据库启动，然后在这个基础上查看丢失的数据程度，安排数据修复的事宜。

当然从我的角度来说，怎么去快速复现这个问题呢。我用自己写的快速搭建测试主从环境的脚本（https://github.com/jeanron100/mysql_slaves，后期有一位大牛建议用Python来做，最近在考虑），分分钟即可搞定。

我们创建一个表test,指定id,name两个字段。然后开启显式事务。

create table test(id int primary key,name varchar(30) not null);

显式开启一个事务：

begin; insert into test values(1,'a'); insert into test values(2,'b'); insert into test values(3,'c');

不提交，我们直接查看mysql的服务进程，直接Kill掉。默认情况下双1指标是开启的，我们直接模拟断电重启，看看后台的处理情况：

2017-09-13 15:05:11 35556 [Note] InnoDB: Highest supported file format is Barracuda. 2017-09-13 15:05:11 35556 [Note] InnoDB: The log sequence numbers 1625987 and 1625987 in ibdata files do not match the log sequence number 1640654 in the ib_logfiles! 2017-09-13 15:05:11 35556 [Note] InnoDB: Database was not shutdown normally! 2017-09-13 15:05:11 35556 [Note] InnoDB: Starting crash recovery. 2017-09-13 15:05:11 35556 [Note] InnoDB: Reading tablespace information from the .ibd files... 2017-09-13 15:05:11 35556 [Note] InnoDB: Restoring possible half-written data pages 2017-09-13 15:05:11 35556 [Note] InnoDB: from the doublewrite buffer... InnoDB: 1 transaction(s) which must be rolled back or cleaned up InnoDB: in total 3 row operations to undo InnoDB: Trx id counter is 2304 2017-09-13 15:05:11 35556 [Note] InnoDB: 128 rollback segment(s) are active. InnoDB: Starting in background the rollback of uncommitted transactions 2017-09-13 15:05:11 7f5ccc3d1700 InnoDB: Rolling back trx with id 1806, 3 rows to undo 2017-09-13 15:05:11 35556 [Note] InnoDB: Rollback of trx with id 1806 completed 2017-09-13 15:05:11 7f5ccc3d1700 InnoDB: Rollback of non-prepared transactions completed 2017-09-13 15:05:11 35556 [Note] InnoDB: Waiting for purge to start 2017-09-13 15:05:11 35556 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.6.14-rel62.0 started; log sequence number 1640654 2017-09-13 15:05:11 35556 [Note] Recovering after a crash using binlog 2017-09-13 15:05:11 35556 [Note] Starting crash recovery... 2017-09-13 15:05:11 35556 [Note] Crash recovery finished.

可以看到后台检测到了上次的异常宕机，然后开启崩溃恢复，InnoDB检测到日志LSN是1625987 而系统数据文件ibd的LSN为1625987 ，和ib_logfiles里面的LSN不匹配。后面就是一系列的恢复，前滚，恢复，回滚。最后表里的数据为空，证明之前的事务都已经回滚了。

所以基于上面的情况，我们明白开启了事务，基本情况下这个问题是不会出现的，什么时候会抛出开始的错误呢。

我们继续测试，开启一个显式事务，不提交。

begin; insert into test values(1,'a'); insert into test values(2,'b'); insert into test values(3,'c');

然后杀掉mysql的服务进程，找到mysql的数据目录下，删除redo文件。完成后我们重启数据库。

这个时候就抛出了和截图类似的错误。

2017-09-13 16:05:14 36896 [Note] InnoDB: Highest supported file format is Barracuda. 2017-09-13 16:05:14 7f73450a97e0 InnoDB: Error: page 7 log sequence number 1627722 InnoDB: is in the future! Current system log sequence number 1626124. 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.

这个问题目前的影响范围其实还不明显，因为尽管如此，我们还是能够写入数据的。

mysql> insert into test values(1,'a'); Query OK, 1 row affected (0.04 sec) mysql> select *from test; +----+------+ | id | name | +----+------+ | 1 | a | +----+------+ 1 row in set (0.00 sec)

关于崩溃恢复，有一个数据参数尤其需要注意，那就是innodb_force_recovery，这个参数默认值为0，如果为非0的值（范围为1-6），会有下面的影响范围。

1 (SRV_FORCE_IGNORE_CORRUPT): 忽略检查到的corrupt页。

2 (SRV_FORCE_NO_BACKGROUND): 阻止主线程的运行，如主线程需要执行full purge操作，会导致crash。

3 (SRV_FORCE_NO_TRX_UNDO): 不执行事务回滚操作。

4 (SRV_FORCE_NO_IBUF_MERGE): 不执行插入缓冲的合并操作。

5 (SRV_FORCE_NO_UNDO_LOG_SCAN):不查看重做日志，InnoDB存储引擎会将未提交的事务视为已提交。

6 (SRV_FORCE_NO_LOG_REDO): 不执行前滚的操作。

当然这个参数的设置修改是需要重启MySQL服务的。

mysql> set global innodb_force_recovery=2; ERROR 1238 (HY000): Variable 'innodb_force_recovery' is a read only variable

在此假设我们设置为2，再次复现这个问题问题，你就会发现，数据库暂时是可以启动的，但是数据只能查询，DML操作都会抛错。

mysql> select *from test; Empty set (0.00 sec) mysql> mysql> insert into test values(1,'a'); ERROR 1030 (HY000): Got error -1 from storage engine

按照这个影响的范围来评估force_recovery的值，我们就可以做相应的取舍了。如果MySQL服务无法正常启动，就可以修改这个参数值来调整，先满足服务可持续性的基本问题。然后评估后导出重要的数据来。