今天有个网友问我一个MySQL的恢复问题。提供的截图如下。
对于这个问题，在一些断电的场景下还是可能出现的。我首先是要确认是否为线上业务还是测试环境，线上业务来说这个影响还是很大的。如果数据库无法启动，首要任务还是把数据库启动，然后在这个基础上查看丢失的数据程度，安排数据修复的事宜。
当然从我的角度来说，怎么去快速复现这个问题呢。我用自己写的快速搭建测试主从环境的脚本(https://github.com/jeanron100/mysql_slaves，后期有一位大牛建议用Python来做，最近在考虑)，分分钟即可搞定。
我们创建一个表test,指定id,name两个字段。然后开启显式事务。
create table test(id int primary key,name varchar(30) not null);
- 1.
显式开启一个事务：
begin;
insert into test values(1,'a');
insert into test values(2,'b');
insert into test values(3,'c');
- 1.
- 2.
- 3.
- 4.
不提交，我们直接查看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.
- 1.
- 2.
- 3.
- 4.
- 5.
- 6.
- 7.
- 8.
- 9.
- 10.
- 11.
- 12.
- 13.
- 14.
- 15.
- 16.
- 17.
- 18.
- 19.
- 20.
- 21.
- 22.
- 23.
- 24.
- 25.
- 26.
- 27.
- 28.
- 29.
- 30.
- 31.
- 32.
- 33.
- 34.
- 35.
- 36.
- 37.
- 38.
- 39.
可以看到后台检测到了上次的异常宕机，然后开启崩溃恢复，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');
- 1.
- 2.
- 3.
- 4.
- 5.
- 6.
- 7.
然后杀掉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.
- 1.
- 2.
- 3.
- 4.
- 5.
- 6.
- 7.
- 8.
- 9.
- 10.
- 11.
- 12.
- 13.
这个问题目前的影响范围其实还不明显，因为尽管如此，我们还是能够写入数据的。
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)
- 1.
- 2.
- 3.
- 4.
- 5.
- 6.
- 7.
- 8.
- 9.
- 10.
- 11.
- 12.
- 13.
- 14.
- 15.
- 16.
- 17.
关于崩溃恢复，有一个数据参数尤其需要注意，那就是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
- 1.
- 2.
- 3.
在此假设我们设置为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
- 1.
- 2.
- 3.
- 4.
- 5.
- 6.
- 7.
- 8.
- 9.
按照这个影响的范围来评估force_recovery的值，我们就可以做相应的取舍了。如果MySQL服务无法正常启动，就可以修改这个参数值来调整，先满足服务可持续性的基本问题。然后评估后导出重要的数据来。
