当 MySQL 数据库遭到攻击篡改后 使用备份和 binlog 进行数据恢复

Question

本文主要描述了 MySQL 遭到攻击篡改数据，利用从库的备份和主库的 Binlog 进行不完全恢复。

一、发现问题

今天是 2014-09-26，开发大清早就说昨晚数据库遭到了攻击。数据库中某文章表的文章内容字段遭到篡改，全部改成了同一篇文章。

通过查看日制 发现 数据是在 2014-09-25 21:53:57 遭到篡改。

所有的内容全部被改成了如下：

我把文章贴出来，先谴责一下，很可能是某旅游社的人为了打广告 雇人干的。

二、解决方法

这个库我们是每天凌晨备份，保留 30 天的备份。主库的 Binlog 保留时间为 7 天。

因此很容易想到的方法是将从库 2014-09-25 凌晨的备份拿出来恢复，然后通过主库的 Binlog 通过时间段来筛选出凌晨至 2014-09-25 21:53:56 的所有更改，之后的数据，经业务确认，可以舍弃掉。或者后面再通过其他方法慢慢将这部分数据找出来。但是当务之急，是立马恢复数据库。

三、找备份及时间点

在备份的从库上检查备份：

crontab -l 
#0 3 * * * /data/opdir/mysqlbak/backup_mysqldump.sh 6084 >> /data/opdir/mysqlbak/6084/mysql-bakup.log 2>&1

发现备份任务让注释了

查看备份文件：

[root@localhost 6084]# ll
total 128
drwxr-xr-x 2 root root 4096 Aug 25 03:13 20140825
drwxr-xr-x 2 root root 4096 Aug 26 03:13 20140826
drwxr-xr-x 2 root root 4096 Aug 27 03:13 20140827
drwxr-xr-x 2 root root 4096 Aug 28 03:13 20140828
drwxr-xr-x 2 root root 4096 Aug 29 03:13 20140829
drwxr-xr-x 2 root root 4096 Aug 30 03:13 20140830
drwxr-xr-x 2 root root 4096 Aug 31 03:13 20140831
drwxr-xr-x 2 root root 4096 Sep  1 03:13 20140901
drwxr-xr-x 2 root root 4096 Sep  2 03:13 20140902
drwxr-xr-x 2 root root 4096 Sep  3 03:13 20140903
drwxr-xr-x 2 root root 4096 Sep  4 03:13 20140904
drwxr-xr-x 2 root root 4096 Sep  5 03:13 20140905
drwxr-xr-x 2 root root 4096 Sep  6 03:13 20140906
drwxr-xr-x 2 root root 4096 Sep  7 03:13 20140907
drwxr-xr-x 2 root root 4096 Sep  8 03:13 20140908
drwxr-xr-x 2 root root 4096 Sep  9 03:13 20140909
drwxr-xr-x 2 root root 4096 Sep 10 03:13 20140910
drwxr-xr-x 2 root root 4096 Sep 11 03:13 20140911
drwxr-xr-x 2 root root 4096 Sep 12 03:13 20140912
drwxr-xr-x 2 root root 4096 Sep 13 03:13 20140913
drwxr-xr-x 2 root root 4096 Sep 14 03:13 20140914
drwxr-xr-x 2 root root 4096 Sep 15 03:13 20140915
drwxr-xr-x 2 root root 4096 Sep 16 03:13 20140916
drwxr-xr-x 2 root root 4096 Sep 17 03:13 20140917
drwxr-xr-x 2 root root 4096 Sep 18 03:14 20140918
drwxr-xr-x 2 root root 4096 Sep 19 03:14 20140919
drwxr-xr-x 2 root root 4096 Sep 20 03:13 20140920
drwxr-xr-x 2 root root 4096 Sep 21 03:13 20140921
drwxr-xr-x 2 root root 4096 Sep 22 03:14 20140922
drwxr-xr-x 2 root root 4096 Sep 23 18:33 20140923
-rw-r--r-- 1 root root 5475 Sep 23 18:33 mysql-bakup.log

备份只到 20140923 日，下午 18:33 分。

备份日志最后一段截取：

tail -n 5 mysql-bakup.log 
deleting backup of 30 days ago -- 20140824 
2014-09-23 18:19:12 begin backup ...
20140824 deleted OK 
2014-09-23 18:33:43 end backup ...

因为这些表是在从库备份的，而且表都是 MyiSAM 的表。查看备份脚本，是先 Stop Slave 之后，才开始备份，因此从备份脚本输出的日志中找到备份开始的时间是：

2014-09-23 18:19:12

通过：

Drwxr-xr-x 2 root root 4096 Sep 23 18:33 20140923

可看到结束时间是： 2014-09-23 18:33:00

现在考虑到底是以备份开始的时间： 2014-09-23 18:19:12 为 Start-DateTime 还是以 2014-09-23 18:33:00 为 Start-DateTime。

前面 提到备份脚本是从库进行备份的，是在 2014-09-23 18:19:12 开始的，在这个时刻备份开始，执行了 Stop Slave；因此整个备份的状态反映的是 从库2014-09-23 18:19:12 这个时间的状态 。而且通过监控可以看到在这个时间点， 从库的延迟为 0 ，因此可以认为这个备份就是 主库在这个时间的备份 。

NOTES：

（有人可能会因为从库上有 Binlog，从库也会接受主库的 Binlog 之类的机制而造成混淆。这里要结合我们具体的备份方式和恢复方式来看，以选出正确的时间点。）

前面提到通过日志查到遭到篡改的时间为：2014-09-25 21:53:57，因此可以将 2014-09-25 21:53:56 作为 Stop-DateTime

因此 Binlog 命令应该是这样：

mysqlbinlog --database=[db_name] --start-datetime='2014-09-23 18:19:12' --stop-datetime='2014-09-25 21:53:56' [binlog_name] > binlog_name0000x.sql 

四、具体的恢复操作

清楚了这些，具体的操作就简单了：

1.从备份机拷贝备份：

scp <备份机 IP>:/data/MySQLbak/20140923/20140923.db_name.gz <恢复测试机 IP>:/data/opdir/20140926

2.恢复测试机 解压：

gunzip 20140923.db_name.gz

3.恢复测试机导入（测试恢复库中之前没有 db_name 这个库)：

mysql -uroot -pxxxxxx -S /tmp/mysql.sock < 20140923.db_name

4.将主库的 Binlog 拷贝到恢复测试机：

查看主库 Binlog

-rw-rw---- 1 mysql mysql  87669492 Sep 23 00:00 mysql-bin.000469
-rw-rw---- 1 mysql mysql 268436559 Sep 23 04:20 mysql-bin.000470
-rw-rw---- 1 mysql mysql 268435558 Sep 23 17:32 mysql-bin.000471
-rw-rw---- 1 mysql mysql  37425262 Sep 24 00:00 mysql-bin.000472
-rw-rw---- 1 mysql mysql 137389819 Sep 25 00:00 mysql-bin.000473
-rw-rw---- 1 mysql mysql 147386521 Sep 26 00:00 mysql-bin.000474

我们需要的 Binlog 时间段为：2014-09-23 18:28:00 至 2014-09-25 21:53:56 因此只需要：

-rw-rw---- 1 mysql mysql 37425262 Sep 24 00:00 mysql-bin.000472 
-rw-rw---- 1 mysql mysql 137389819 Sep 25 00:00 mysql-bin.000473 
-rw-rw---- 1 mysql mysql 147386521 Sep 26 00:00 mysql-bin.000474

将这 3 个 Binlog Copy 过去：

scp mysql-bin.000472 <恢复测试机 IP>:/data/opdir/20140926 
scp mysql-bin.000473 <恢复测试机 IP>:/data/opdir/20140926 
scp mysql-bin.000474 <恢复测试机 IP>:/data/opdir/20140926

5.使用 MySQLBinlog 生成 SQL 脚本：

mysqlbinlog --database=[db_name] --start-datetime='2014-09-23 18:19:12' --stop-datetime='2014-09-25 21:53:56' mysql-bin.000472 > 472.SQL
mysqlbinlog --database=[db_name] --start-datetime='2014-09-23 18:19:12' --stop-datetime='2014-09-25 21:53:56' mysql-bin.000473 > 473.SQL
mysqlbinlog --database=[db_name] --start-datetime='2014-09-23 18:19:12' --stop-datetime='2014-09-25 21:53:56' mysql-bin.000474 > 474SQL

6.Binlog 生成的 SQL 脚本导入：

待 20140923.db_name 导入到恢复测试库之后，将 MySQLBinlog 生成的 SQL 脚本导入到数据库中：

mysql -uroot -pxxxxxx -S /tmp/mysql.sock db_name < 472.sql 
mysql -uroot -pxxxxxx -S /tmp/mysql.sock db_name < 473.sql 
mysql -uroot -pxxxxxx -S /tmp/mysql.sock db_name < 474.sql

7.导入完成后检查数据正确性：

大致看一下数据的情况，然后可以通过时间字段来看一下情况：

mysql> select max(createtime),max(updatetime) from table_name;
+-----------------+-----------------+
| max(createtime) | max(updatetime) |
+-----------------+-----------------+
|      1411648043 |      1411648043 |
+-----------------+-----------------+
1 row in set (0.00 sec)

时间差不多为 晚上 20:27 了

这个判断，作为 DBA，查看部分数据，只能起到辅助作用，具体的需要 到底是否 OK，需要业务开发的人来判断。

经过业务开发确认后，即可将该数据导出后，再导入到线上主库中。

8、将该库导出，并压缩：

mysqldump -uroot -pxxxxxx -S /tmp/mysql.sock -q db_name table_name > table_name.sql 

压缩：

gzip table_name.sql

scp 到主库 （复制的时候，请将网络因素考虑进去，确认不会占用过多带宽而影响其他线上业务）

9.恢复测试的数据导入到线上主库中：

线上主库操作：

操作之前，最好让开发把应用业务那段先暂停，否则可能会影响导入。比如这个表示 MyISAM 的，应用那边如果不听有 update 进来，就会阻塞数据导入。

a、主库将原始被篡改的表改名：（不要上来就 drop，先 rename，后续确认没问题了再考虑 drop，因为很多问题不是一瞬间就能全部反映上来的）

rename table_name to old_table_name;

b、解压：

gunzip -d table_name.sql.gz

c、导入新表数据：

mysql -uroot -pxxxxxx -S /tmp/mysql.sock db_name < table_name.sql

后面就需要开发来进一步验证数据是否 OK 了。 验证没问题后，再启动应用程序。