MySQL基于Binlog的数据恢复实战

作者：AshesCat

1、环境状态说明

操作系统：CentOS 7.7
MySQL版本：5.7.30，搭建主从
开启binlog，binlog_format=row
备份情况：每天00:00对数据库进行全量备份
恢复原因：某日22:00左右，执行了批量update语句，需要回滚

2、恢复流程说明

按照正反两种方式分别进行测试恢复

2.1 正向恢复

主要思路

通过全量备份恢复当日0:00时间点的数据
通过binlog恢复当日0:00-22:00错误语句之前的全部语句

2.2 反向恢复

主要思路

使用binlog2sql从binlog日志中提取错误语句的反向语句
在当前已经执行了错误语句的数据库执行反向语句，将数据恢复至错误语句执行前的状态

3、数据准备

3.1 查询当前binlog数据状态

mysql> show master status;
+------------------+-----------+--------------+------------------+
| File             | Position  | Binlog_Do_DB | Binlog_Ignore_DB |
+------------------+-----------+--------------+------------------+
| mysql-bin.000027 | 851010973 |              |                  |
+------------------+-----------+--------------+------------------+
1 row in set (0.00 sec)

[root@mysql-01 ~]# ll /data/mysql5730/mysql-bin.*
-rw-r----- 1 mysql mysql 1073741880 9月   6 03:02 /data/mysql5730/mysql-bin.000023
-rw-r----- 1 mysql mysql 1073900114 9月   8 16:31 /data/mysql5730/mysql-bin.000024
-rw-r----- 1 mysql mysql 1074333543 9月   9 12:07 /data/mysql5730/mysql-bin.000025
-rw-r----- 1 mysql mysql 1094225409 9月  13 22:01 /data/mysql5730/mysql-bin.000026
-rw-r----- 1 mysql mysql  690570884 9月  14 00:42 /data/mysql5730/mysql-bin.000027

通过以上查询可以得知，当前使用的binlog日志文件为mysql-bin.000027，最后更新时间为9月14日0:42，上一个binlog文件mysql-bin.000026是9月9日12:07左右创建，最后更新时间为9月13日22:01。可以确定出错update语句应该按照时间应该记录在26的结尾和27开始的位置

3.2 查找恢复position区间

正向恢复开始的position点，会记录在每天0点备份的备份文件内。

[root@mysql-01 ~]# grep "CHANGE MASTER" /tmp/service_platform_2021-09-13.sql
-- CHANGE MASTER TO MASTER_LOG_FILE='mysql-bin.000026', MASTER_LOG_POS=890333336;

结束的position点，应该选取错误update语句执行前的一个事务结束点。
按照大概时间截取2021-09-13 21:55:00-2021-09-13 22:05的26和27两个文件的binlog日志

[root@mysql-01 ~]# mysqlbinlog --start-datetime='2021-09-13 21:55:00' --stop-datetime='2021-09-13 22:05'  /data/mysql5730/mysql-bin.000026  > /tmp/bin26.sq
[root@mysql-01 ~]# mysqlbinlog --start-datetime='2021-09-13 21:55:00' --stop-datetime='2021-09-13 22:05'  /data/mysql5730/mysql-bin.000027  > /tmp/bin27.sql

完整一条binlog事务记录

BEGIN                 # 事务开始
/*!*/;
# at 918610296        # 事务开始position
#210913 22:01:05 server id 120  end_log_pos 918610654 CRC32 0x1488200a 	Table_map: `service_platform`.`student` mapped to number 24404
# at 918610654
#210913 22:01:05 server id 120  end_log_pos 918611652 CRC32 0xf4a9a8c3 	Update_rows: table id 24404 flags: STMT_END_F

BINLOG '              # 具体执行的sql（base64编码）
oQ/GYBN4AAAAZgEAAN7iwDYAAFRfAAAAAAEAGWVudHJhbmNlX3NlcnZpY2VfcGxhdGZvcm0AB3N0
dWRlbnQAogMDAwMPDwMPDwMPAwMIAw8DAw8DAwMDAwMPDw8IDwMDDwMPDw8DAw8DDw8PAwMIDwMD
AwMPDwMICAMDAwMDAwQDAwgDAwMDDw8DDwMPDwMDDwMPAwMPAwMPDw8PAwMPAwMDDw8DAwMDAw8P
DwMDAwMDAwMDAw8PDw8PDwMDAwMDDwMPAwMDAwMDAwMPCA8DAwMDAwMDAwMDAwMDDwMDDxEDA2qA
AEAAAAEAAYAAGAAABAAgAARAAIAAgAAABAABgACAAAAEAAFAAEAAAAQABAQABAABgAAAAgAEgAAA
BAAEAAGQAQABAAEoAAABAAEoAAACQAAAAQABgAAAAgABAAEgAEAAQAAAAUAAQAAA/v//////////
//////////////8DCiCIFA==
oQ/GYB94AAAA5gMAAMTmwDYAAFRfAAAAAAEAAgCi////////////////////////////////////
////////////////////BgEBHwBoif//3v3z//////5//jX/3VsIAOqlAQAIMjE5OTI0MjAGNDgw
NDYxAAAAAAkA6YOt5qCp5a2cQR99ABIxMTAxMTYyMDA5MDUxMjE4MjYqWIkAG1yJAIBLCEoAAAAA
2o6JAAMxNTYkrgEAKgDmgIDmn5TljLrov47lrr7ljJfot681NeWPt+alvDLljZXlhYM2MDHlrqQk
rgEAJK4BAKKOAQAkngEAJK4BAAnliJjpgrHlrZBaAS4AQR99ABIxMTAyMjcxOTg3MDUxNjA2MjK4
........................................MzQwNzE2MAAAAAAIMjE5OTI0MjCa3AEAAAAA
ACoA5oCA5p+U5Yy66L+O5a6+5YyX6LevNTXlj7fmpbwy5Y2V5YWDNjAx5a6kFQDvvKcxMTAxMTYy
MDA5MDUxMjE4MjaC4AEABgA5NTgxMzAGADEzMDAwMAAAAAADADE1NgMAMTU2BuWksei0pQIAAAAB
AAAAJK4BAAbkuqznsY0G5Lqs57GNYMYPocOoqfQ=
'/*!*/;
# at 918611652
#210913 22:01:05 server id 120  end_log_pos 918611683 CRC32 0xda6fdc6e 	Xid = 154913465
COMMIT/*!*/;          # 事务结束 结束position 918611683

经过确认，在22:00:53时，有一个大事务执行，基本可以确定是这个事务，事务开始position是918611748，结束position是1094225331。

# at 918611748
#210913 22:00:53 server id 120  end_log_pos 918611841 CRC32 0xa4f84b66 	Query	thread_id=419432	exec_time=0	error_code=0
SET TIMESTAMP=1623592853/*!*/;
BEGIN
/*!*/;
# at 918611841
#210913 22:00:53 server id 120  end_log_pos 918612199 CRC32 0xc4e1a859 	Table_map: `service_platform`.`student` mapped to number 24404
# at 918612199
#210913 22:00:53 server id 120  end_log_pos 918619761 CRC32 0xdea1bb51 	Update_rows: table id 24404
# at 918619761
#210913 22:00:53 server id 120  end_log_pos 918627679 CRC32 0xad1ba65d 	Update_rows: table id 24404
# at 918627679
#210913 22:00:53 server id 120  end_log_pos 918635509 CRC32 0xf55f5800 	Update_rows: table id 24404
# at 918635509
#210913 22:00:53 server id 120  end_log_pos 918643369 CRC32 0x484ffffc 	Update_rows: table id 24404
# at 918643369
#210913 22:00:53 server id 120  end_log_pos 918651107 CRC32 0xab13fd26 	Update_rows: table id 24404
# at 918651107
#210913 22:00:53 server id 120  end_log_pos 918658547 CRC32 0xbc4b489c 	Update_rows: table id 24404
.....

'/*!*/;
# at 1094225331
#210913 22:00:53 server id 120  end_log_pos 1094225362 CRC32 0x175cc5e4 	Xid = 154913333
COMMIT/*!*/;

3.3 position点确认

当日当天0:00到执行错误语句前的position区间为890333336 - 918611748，正向恢复使用
当日执行的错误语句事务的position区间为918611748 - 1094225331，反向恢复使用

4、操作恢复

4.1 正向恢复

4.1.1 恢复备份数据

将2021-09-13 00:00:00的全备数据恢复至数据库。

[root@localhost ~]# mysql -uroot -p < service_platform_2021-09-13.sql
Enter password:

查看当前数据状态，此字段的new_id在当日日当天被修改。

mysql> use service_platform;
Database changed
mysql> select new_id, town_id from student where id = '15132600';
+-------------+---------+
| new_id | town_id |
+-------------+---------+
| 108    |     105 |      # new_id = 108
+-------------+---------+
1 row in set (0.01 sec)

4.1.2 恢复binlog日志

截取当日当天binlog日志

[root@localhost ~]# mysqlbinlog   --start-position=890333336 --stop-position=918611748  mysql-bin.000026 > /tmp/a.sql
[root@localhost ~]# ll -h /tmp/a.sql 
-rw-r--r-- 1 root root 51M 9 15 15:48 /tmp/a.sql

重写binlog日志

mysql> source /tmp/a.sql

Query OK, 0 rows affected (0.00 sec)

....

Query OK, 0 rows affected (0.00 sec)

Query OK, 0 rows affected (0.00 sec)

mysql>

4.1.3 检查数据恢复状态

mysql> use service_platform;
Database changed
mysql> select new_id, town_id from student where id = '15132600';
+-------------+---------+
| new_id | town_id |
+-------------+---------+
|    105 |     105 |
+-------------+---------+
1 row in set (0.00 sec)

至此，正向恢复数据完成

4.2 反向恢复

反向恢复时通过binlog2sql，将错误执行的update语句反转，再update回来

4.2.1 安装binlog2sql

项目地址：
https://github.com/danfengcao/binlog2sql

# 安装epel源
wget http://dl.fedoraproject.org/pub/epel/epel-release-latest-7.noarch.rpm   
rpm -ivh epel-release-latest-7.noarch.rpm

# 安装git pip
yum -y install git python-pip 

# git下载binlog2sql
[root@localhost ~]# git clone https://github.com/danfengcao/binlog2sql.git && cd binlog2sql
Cloning into 'binlog2sql'...
remote: Enumerating objects: 323, done.
remote: Total 323 (delta 0), reused 0 (delta 0), pack-reused 323
Receiving objects: 100% (323/323), 153.26 KiB | 0 bytes/s, done.
Resolving deltas: 100% (170/170), done.
[root@localhost binlog2sql]# pip install -r requirements.txt

4.2.2 生成反转sql

根据错误语句的position区间918611748 - 1094225331，生成反向语句。
注意：此语句必须在原库执行，数据库必须是当前错误状态，且数据库执行此错误语句后这些数据未发生其它更改，binlog日志也可正常使用。

[root@localhost mysql]# python /root/binlog2sql/binlog2sql/binlog2sql.py -h 127.0.0.1  -u root -p -d service_platform -t student --start-file='mysql-bin.000026' --start-position=918611748 --stop-position=1094225331 -B >/tmp/b.sql
[root@localhost mysql]# ll -h /tmp/b.sql 
-rw-r--r-- 1 root root 1.2G 9 15 16:31 /tmp/b.sql

参数说明

-h                      # 主机ip
-P                      # 端口号，这里的P是大写
-u                      # 用户名为root
-p                      # 密码
-d                      # 指定过滤数据库（可忽略）
-t                      # 指定过滤表（可忽略）
–-start-file            # 开始binlog文件
--stop-file             # 结束binlog文件，可忽略，忽略默认为start-file
-B                      # 生成反向sql，不加是生成正向sql
--start-position        # 开始position位置点
--stop-position         # 结束position位置点（可忽略，忽略默认为binlog文件末尾）

4.2.3 解决sql虚拟字段问题（如果有）

binlog内存储的update语句是针对所有列操作的，如果其中存在虚拟列，则需要先进行删除。
可通过vim或者sed对文件进行操作，将虚拟列相关数据变更为空值。
相关报错如下：

ERROR 3105 (HY000): The value specified for generated column 'student_kind' in table 'student' is not allowed.

具体需替换内容联系开发索取

[root@localhost mysql]# sed -i s#`student_kind`='AAA',##g /tmp/b.sql
[root@localhost mysql]# sed -i s#`student_kind`='BBB',##g /tmp/b.sql
[root@localhost mysql]# sed -i s#`student_kind`='CCC',##g /tmp/b.sql
[root@localhost mysql]# sed -i s#`student_kind`='DDD',##g /tmp/b.sql
[root@localhost mysql]# sed -i s#`student_kind`='EEE',##g /tmp/b.sql
[root@localhost mysql]# sed -i s#`student_kind`='FFF',##g /tmp/b.sql
[root@localhost mysql]# sed -i s#\`new_id\`=\d\{6\},##g /tmp/b.sql

4.2.4 写入反向sql

mysql> source /tmp/b.sql

4.2.5 检查数据恢复状态

mysql> use service_platform;
Database changed
mysql> select new_id, town_id from student where id = '15132600';
+-------------+---------+
| new_id | town_id |
+-------------+---------+
|    105 |     105 |
+-------------+---------+
1 row in set (0.00 sec)

至此，反向恢复数据完成

See you ~

山山仙人博客