《叶问》35期，binlog解析出来的日志为何无法恢复

今天药忘吃喽~ 2022-09-01 15:43 123阅读 0赞

本文首发于 GreatSQL社区 微信公众号。

原创内容未经授权不得随意使用，转载请联系小编并注明来源。

问题描述

##  ##

问题来自一位群友，简单说就是用 `mysqlbinlog` 工具读取 binlog 欲进行恢复，却发现数据并没被恢复。

先一起来看下他是怎么做恢复的。

表中原来有几条数据，但不小心被清空了：

[yejr]> select * from t1;
    +----+
    | c1 |
    +----+
    |  1 |
    |  2 |
    |  3 |
    |  4 |
    +----+

查看binlog event，有几条插入数据，最后还有一条 `truncate table` 的"误操作"，现在想要把表数据恢复到误删数据前的状态。

[yejr]> show binlog events in 'binlog.000003';
    +---------------+------+----------------+-----------+-------------+--------------------------------------------------------------------+
    | Log_name      | Pos  | Event_type     | Server_id | End_log_pos | Info                                                               |
    +---------------+------+----------------+-----------+-------------+--------------------------------------------------------------------+
    | binlog.000003 |    4 | Format_desc    |      3306 |         125 | Server ver: 8.0.25-15, Binlog ver: 4                               |
    | binlog.000003 |  125 | Previous_gtids |      3306 |         196 | aaaaaaaa-aaaa-aaaa-aaaa-aaaaaaaaaaa1:1-5                           |
    | binlog.000003 |  196 | Gtid           |      3306 |         282 | SET @@SESSION.GTID_NEXT= 'aaaaaaaa-aaaa-aaaa-aaaa-aaaaaaaaaaa1:6'  |
    | binlog.000003 |  282 | Query          |      3306 |         358 | BEGIN                                                              |
    | binlog.000003 |  358 | Rows_query     |      3306 |         405 | # insert into t1 select 1                                          |
    | binlog.000003 |  405 | Table_map      |      3306 |         454 | table_id: 91 (yejr.t1)                                            |
    | binlog.000003 |  454 | Write_rows     |      3306 |         494 | table_id: 91 flags: STMT_END_F                                     |
    | binlog.000003 |  494 | Xid            |      3306 |         525 | COMMIT /* xid=75 */                                                |
    | binlog.000003 |  525 | Gtid           |      3306 |         611 | SET @@SESSION.GTID_NEXT= 'aaaaaaaa-aaaa-aaaa-aaaa-aaaaaaaaaaa1:7'  |
    | binlog.000003 |  611 | Query          |      3306 |         687 | BEGIN                                                              |
    | binlog.000003 |  687 | Rows_query     |      3306 |         734 | # insert into t1 select 2                                          |
    | binlog.000003 |  734 | Table_map      |      3306 |         783 | table_id: 91 (yejr.t1)                                            |
    | binlog.000003 |  783 | Write_rows     |      3306 |         823 | table_id: 91 flags: STMT_END_F                                     |
    | binlog.000003 |  823 | Xid            |      3306 |         854 | COMMIT /* xid=76 */                                                |
    | binlog.000003 |  854 | Gtid           |      3306 |         940 | SET @@SESSION.GTID_NEXT= 'aaaaaaaa-aaaa-aaaa-aaaa-aaaaaaaaaaa1:8'  |
    | binlog.000003 |  940 | Query          |      3306 |        1016 | BEGIN                                                              |
    | binlog.000003 | 1016 | Rows_query     |      3306 |        1063 | # insert into t1 select 3                                          |
    | binlog.000003 | 1063 | Table_map      |      3306 |        1112 | table_id: 91 (yejr.t1)                                            |
    | binlog.000003 | 1112 | Write_rows     |      3306 |        1152 | table_id: 91 flags: STMT_END_F                                     |
    | binlog.000003 | 1152 | Xid            |      3306 |        1183 | COMMIT /* xid=77 */                                                |
    | binlog.000003 | 1183 | Gtid           |      3306 |        1269 | SET @@SESSION.GTID_NEXT= 'aaaaaaaa-aaaa-aaaa-aaaa-aaaaaaaaaaa1:9'  |
    | binlog.000003 | 1269 | Query          |      3306 |        1345 | BEGIN                                                              |
    | binlog.000003 | 1345 | Rows_query     |      3306 |        1392 | # insert into t1 select 4                                          |
    | binlog.000003 | 1392 | Table_map      |      3306 |        1441 | table_id: 91 (yejr.t1)                                            |
    | binlog.000003 | 1441 | Write_rows     |      3306 |        1481 | table_id: 91 flags: STMT_END_F                                     |
    | binlog.000003 | 1481 | Xid            |      3306 |        1512 | COMMIT /* xid=78 */                                                |
    | binlog.000003 | 1512 | Gtid           |      3306 |        1596 | SET @@SESSION.GTID_NEXT= 'aaaaaaaa-aaaa-aaaa-aaaa-aaaaaaaaaaa1:10' |
    | binlog.000003 | 1596 | Query          |      3306 |        1693 | use `yejr`; truncate table t1 /* xid=87 */                        |
    +---------------+------+----------------+-----------+-------------+--------------------------------------------------------------------+

运行下面的命令想要进行恢复数据，但发现不能正确恢复：

$ mysqlbinlog --start-position=4 --stop-position=1512 binlog.000003 | mysql -f yejr

已经指定了读取binlog的位置是从4开始，到1512截止，因为再下一个event就是"误操作"了。之后查询 yejr.t1 表数据还是空的，没有被正确恢复。

## 问题解决 ##

首先再次强调线上操作要非常谨慎，如果只是普通的DML操作，建议**事先打开事务模式**，这样**万一误操作了还能执行 rollback 回滚**。

但如果是DDL操作，则基本上只能**依赖备份或者延迟从库**，所以务必再三确认是在测试环境还是线上环境，以及即将执行的命令影响如何。

再回到问题本身。

在执行 mysqlbinlog 解析binlog并尝试恢复时，观察新的binlog，确认没有写入新数据，说明确实没执行恢复操作。

解析binlog查看，并没有类似 `SET SQL_LOG_BIN=0` 等忽略binlog的设置，而如果复制SQL指令执行出来手动执行，却是可以成功的。说明binlog本身没问题，是其他原因导致的。

再查看 binlog event 时注意到启用了 **GTID** 模式，在 GTID 模式下有个特点是要求 **全局唯一**。

除了GTID值持续递增之外，有个不容易注意的特点是，当事务GTID在已执行过的GTID集合（Executed\_Gtid\_Set）中的话，就不会再次被执行。假设以下几种场景：

*  假设当前Executed\_Gtid\_Set集合是 1-10，如果下一个GTID是5，**它在这个范围内，则无法被执行**。
 *  假设当前Executed\_Gtid\_Set集合是 1-10, 20-30，如果下一个GTID是13，**不在这个范围内，则可以被执行**。

分别做个测试：

# 查看当前gtid
    [yejr]> show master status;
    +---------------+----------+--------------+------------------+----------------------------------------------+
    | File          | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set                            |
    +---------------+----------+--------------+------------------+----------------------------------------------+
    | binlog.000004 |      762 |              |                  | aaaaaaaa-aaaa-aaaa-aaaa-aaaaaaaaaaa1:1-15:20 |
    +---------------+----------+--------------+------------------+----------------------------------------------+
    
    # 下一个GTID在范围内，不会被执行
    [yejr]> set session gtid_next='aaaaaaaa-aaaa-aaaa-aaaa-aaaaaaaaaaa1:13';
    [yejr]> insert into t1 select 6;
    Query OK, 0 rows affected (0.00 sec)   #<-- 0 rows
    
    # 下一个GTID不在范围内，会被执行
    [yejr]> set session gtid_next='aaaaaaaa-aaaa-aaaa-aaaa-aaaaaaaaaaa1:17';
    [yejr]> insert into t1 select 6;
    Query OK, 1 row affected (0.01 sec)   #<-- 1 row affected
    Records: 1  Duplicates: 0  Warnings: 0
    
    # 再次查看gtid
    [yejr]> show master status;
    +---------------+----------+--------------+------------------+-------------------------------------------------+
    | File          | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set                               |
    +---------------+----------+--------------+------------------+-------------------------------------------------+
    | binlog.000004 |     1091 |              |                  | aaaaaaaa-aaaa-aaaa-aaaa-aaaaaaaaaaa1:1-15:17:20 |
    +---------------+----------+--------------+------------------+-------------------------------------------------+

验证结果确实如上所说。

知道原因就好办了，查看 `mysqlbinlog` 的帮助文档，查看选项 `--skip-gtids` 的解释：

--skip-gtids        Do not preserve Global Transaction Identifiers; instead
                          make the server execute the transactions as if they were
                          new.

它可以使得解析出来的binlog event不再保留原来的 GTID 信息，这就可以当成新的 event 被执行了。所以，**如果想要从binlog恢复数据，执行mysqlbinlog时，记得加上 --skip-gtids 选项**。

全文完。

Enjoy MySQL :)

--------------------

**文章推荐：**

*  [MGR最佳实践(MGR Best Practice)][MGR_MGR Best Practice]
 *  [万里数据库MGR Bug修复之路][MGR Bug]
 *  [ansible一键安装GreatSQL并构建MGR集群][ansible_GreatSQL_MGR]
 *  [在Docker中部署GreatSQL并构建MGR集群][Docker_GreatSQL_MGR]
 *  [将GreatSQL添加到系统systemd服务][GreatSQL_systemd]
 *  [金融应用场景下跨数据中心的MGR架构方案][MGR]  
    
 *  [InnoDB Cluster+GreatSQL快速部署MGR集群，并实现读写分离和故障自动转移][InnoDB Cluster_GreatSQL_MGR]
 *  [利用GreatSQL部署MGR集群，并完成添加新节点 、滚动升级、切主][GreatSQL_MGR_]
 *  [《叶问》33期，MGR最佳配置参考，PFS里的监测指标要全开吗，mysqld进程占用内存过高怎么排查][33_MGR_PFS_mysqld]

--------------------

扫码加入GreatSQL/MGR交流**QQ群**

![cd7e965fe37b36e8fe35ec181a94735f.png][]

点击文末“**阅读原文**”直达老叶专栏

[MGR_MGR Best Practice]: http://mp.weixin.qq.com/s?__biz=MzkzMTIzMDgwMg%3D%3D&chksm=c26f6633f518ef25f19309e4b01ce5d4527d945a2a030b66a9d9bbaa598cb668eca30cb91a0f&idx=1&mid=2247484174&scene=21&sn=4f795e889e3778876b09143c4ffdc770#wechat_redirect
[MGR Bug]: http://mp.weixin.qq.com/s?__biz=MzkzMTIzMDgwMg%3D%3D&chksm=c26f64abf518edbdb278f1c21e98e39dc73b78397d01c2d583450a1da6d72a4ff32a0ec6db9c&idx=1&mid=2247483798&scene=21&sn=21fc1b1797074e002e1c684263b731e8#wechat_redirect
[ansible_GreatSQL_MGR]: http://mp.weixin.qq.com/s?__biz=MjM5NzAzMTY4NQ%3D%3D&chksm=bd3b404d8a4cc95b9b429093753a7aec8fd990a6b1057646d82726d9debe0f1405477ee83031&idx=1&mid=2653936167&scene=21&sn=76420e523bec1b9399ab7e0138802bcd#wechat_redirect
[Docker_GreatSQL_MGR]: http://mp.weixin.qq.com/s?__biz=MjM5NzAzMTY4NQ%3D%3D&chksm=bd3b40488a4cc95e2f4a7750a3cad05fd70d3b9b5f366ded103e66e16f2cdda6f67fa231803c&idx=1&mid=2653936162&scene=21&sn=fa76aa58c0262d6a4e43c675f305db6d#wechat_redirect
[GreatSQL_systemd]: http://mp.weixin.qq.com/s?__biz=MjM5NzAzMTY4NQ%3D%3D&chksm=bd3b43ea8a4ccafc0edffe28125815e5a490370463d7f7c00436f5d58b47df58affd0afe263d&idx=1&mid=2653936000&scene=21&sn=d21f6f3a89e03c08663df5b34f6b09f8#wechat_redirect
[MGR]: http://mp.weixin.qq.com/s?__biz=MjM5NzAzMTY4NQ%3D%3D&chksm=bd3b43108a4cca06841d2adf3a63dfe6af99df09b09164e8676d99cb08fc5e569bfc543a0ccf&idx=1&mid=2653935994&scene=21&sn=91c596c81944aabd396d33f4924aac26#wechat_redirect
[InnoDB Cluster_GreatSQL_MGR]: http://mp.weixin.qq.com/s?__biz=MjM5NzAzMTY4NQ%3D%3D&chksm=bd3b43308a4cca26c2db9912a9ce5e2d73df1a10e7415f83538742b92e5475a0b11b88e39f4c&idx=1&mid=2653935962&scene=21&sn=38f2acfb147f16ae8daaa6a48a3102ae#wechat_redirect
[GreatSQL_MGR_]: http://mp.weixin.qq.com/s?__biz=MjM5NzAzMTY4NQ%3D%3D&chksm=bd3b43258a4cca336b0260c6b9cfc363f10596c775bdd0408d89dca855f3c7949911aa50ec8f&idx=1&mid=2653935951&scene=21&sn=ec8794371cd6f7677a5355b7e7ac39ea#wechat_redirect
[33_MGR_PFS_mysqld]: http://mp.weixin.qq.com/s?__biz=MjM5NzAzMTY4NQ%3D%3D&chksm=bd3b436b8a4cca7ddf138db1d2342aa19f0452bff97beb2f5015cf0eb377a7d2a6899d1c3c05&idx=1&mid=2653935873&scene=21&sn=7511853d63145b7d72ae533586b6ad81#wechat_redirect
[cd7e965fe37b36e8fe35ec181a94735f.png]: /images/20220829/40d371a7902f4a4b9d2fb908467f2f85.png