Wan Da #5, why can't the logs parsed by binlog be recovered

Welcome to the MySQL technical articles shared by the great SQL community. If you have any questions or want to learn, you can leave a message in the comment area below. After seeing it, you will answer it

Problem description

The problem comes from a group friend. In short, he uses mysqlbinlog tool to read binlog for recovery, but finds that the data has not been recovered.

Let's see how he recovers first.

There were several pieces of data in the table, but they were accidentally emptied:

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

Check binlog event. There are several pieces of inserted data. Finally, there is a "misoperation" of truncate table. Now you want to restore the table data to the state before the data is deleted by mistake.

[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 */                        |

Run the following command to recover data, but it is found that it cannot be recovered correctly:

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

It has been specified that the location of reading binlog starts from 4 and ends at 1512, because the next event is "misoperation". Then query yejr The T1 table data is still empty and has not been recovered correctly.

Problem solving

First of all, it is emphasized that online operations should be very cautious. If it is only an ordinary DML operation, it is recommended to turn on the transaction mode in advance, so that the rollback can be performed in case of misoperation.

However, if it is a DDL operation, it can only rely on backup or delayed slave library. Therefore, it is important to repeatedly confirm whether it is in the test environment or online environment and the impact of the commands to be executed.

Back to the problem itself.

When executing mysqlbinlog, parsing binlog and trying to recover, observe the new binlog and confirm that no new data is written, indicating that the recovery operation is not performed.

Parse binlog to see if there is no similar SET SQL_LOG_BIN=0 ignores the binlog setting, but if the copied SQL instruction is executed manually, it can succeed. This indicates that the binlog itself is OK, which is caused by other reasons.

When viewing binlog event again, you notice that GTID mode is enabled. In GTID mode, one feature is that it requires global uniqueness.

In addition to the continuous increment of GTID value, it is not easy to notice that when the transaction GTID is in the Executed_Gtid_Set, it will not be executed again. Suppose the following scenarios:

Assume current executed_ GTID_ The set set is 1-10. If the next GTID is 5 and it is in this range, it cannot be executed.
Assume current executed_ GTID_ The set set is 1-10 and 20-30. If the next GTID is 13 and is not in this range, it can be executed.

Make a test:

# View current 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 |
+---------------+----------+--------------+------------------+----------------------------------------------+

# The next GTID is in the range and will not be executed
[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

# The next GTID is out of range and will be executed
[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

# Review the gtid again
[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 |
+---------------+----------+--------------+------------------+-------------------------------------------------+

The verification results are indeed as mentioned above.

It's easy to know the reason. Check the help document of mysqlbinlog and the explanation of the option skip gtids:

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

It can make the parsed binlog event no longer retain the original GTID information, which can be executed as a new event. Therefore, if you want to recover data from binlog, remember to add the -- skip gtids option when executing mysqlbinlog.

End of the full text.

Enjoy MySQL :)

Article recommendation:

GreatSQL MGR FAQ
https://mp.weixin.qq.com/s/J6...

Wan Da #12, how can the MGR cluster automatically select the master without manual intervention
https://mp.weixin.qq.com/s/07...

"2021 data technology Carnival · ON LINE": evolution and practice of MySQL high availability architecture
https://mp.weixin.qq.com/s/u7...

Packet capture analysis of where an sql statement is slow
https://mp.weixin.qq.com/s/AY...

Wan Da #15, what are the conditions that may cause the MGR service to fail to start
https://mp.weixin.qq.com/s/in...

Technology sharing | why MGR consistency mode does not recommend AFTER
https://mp.weixin.qq.com/s/rN...

About GreatSQL

GreatSQL is a MySQL branch maintained by Wanli database. It focuses on improving the reliability and performance of MGR and supports the parallel query feature of InnoDB. It is a branch version of MySQL suitable for financial applications.

Gitee:
https://gitee.com/GreatSQL/Gr...

GitHub:
https://github.com/GreatSQL/G...

Bilibili:
https://space.bilibili.com/13...

Wechat & QQ group:
You can search and add GreatSQL community assistant wechat friends, send verification information "add group" to join GreatSQL/MGR communication wechat group

QQ group: 533341697
Wechat assistant: wanlidbc

This article is composed of blog one article multi posting platform OpenWrite release!

Keywords: Database MySQL SQL

Added by pengu on Mon, 10 Jan 2022 05:09:39 +0200