利用MyFlash闪回丢失数据

佚名 7年前 (2018-06-01) Mysql 755人围观抢沙发百度已收录

MyFlash is an open source tool released by Meituan-Dianping which can be used to flashback MySQL DML data.here's the github link: https://github.com/Meituan-Dianping/MyFlash after downloaded the tool and extracted the zip package,i got this structure:

 1 [root@zlm1 16:25:26 /vagrant/MyFlash-master]
 2 #ls -l
 3 total 8
 4 drwxrwxrwx 1 vagrant vagrant 0 Jun 1 16:17 binary
 5 -rwxrwxrwx 1 vagrant vagrant 95 Oct 25 2017 build.sh
 6 drwxrwxrwx 1 vagrant vagrant 0 Jun 1 16:17 doc
 7 -rwxrwxrwx 1 vagrant vagrant 1103 Oct 25 2017 License.md
 8 -rwxrwxrwx 1 vagrant vagrant 1273 Oct 25 2017 README.md
 9 drwxrwxrwx 1 vagrant vagrant 0 Jun 1 16:17 source
10 drwxrwxrwx 1 vagrant vagrant 4096 Jun 1 16:17 testbinlog

the official document recommend to install the tool by dynamic compliling link way to install,but i prefer to use the binary way instead.let's see the parameter and usage of the command:

SRE实战互联网时代守护先锋，助力企业售后服务体系运筹帷幄！一键直达领取阿里云限量特价优惠。

 1 [root@zlm1 16:27:20 /vagrant/MyFlash-master/binary]
 2 #./flashback --help
 3 Usage:
 4   flashback [OPTION...]
 5 Help Options:
 6   -h, --help Show help options
 7 Application Options:
 8   --databaseNames databaseName to apply. if multiple, seperate by comma(,)
 9   --tableNames tableName to apply. if multiple, seperate by comma(,)
10   --start-position start position
11   --stop-position stop position
12   --start-datetime start time (format %Y-%m-%d %H:%M:%S)
13   --stop-datetime stop time (format %Y-%m-%d %H:%M:%S)
14   --sqlTypes sql type to filter . support INSERT, UPDATE ,DELETE. if multiple, seperate by comma(,)
15   --maxSplitSize max file size after split, the uint is M
16   --binlogFileNames binlog files to process. if multiple, seperate by comma(,)
17   --outBinlogFileNameBase output binlog file name base
18   --logLevel log level, available option is debug,warning,error
19   --include-gtids gtids to process
20   --exclude-gtids gtids to skip

View Code first of all,create the test environment as below:

 1 root@localhost:mysql3306.sock [zlm]05:35:42>create table test_flashbk(
 2     -> id bigint not null auto_increment,
 3     -> name varchar(20) not null default '',
 4     -> primary key(id)
 5     -> ) engine=innodb default charset=utf8mb4;
 6 Query OK, 0 rows affected (0.04 sec)
 7  
 8 root@localhost:mysql3306.sock [zlm]05:35:53>delimiter //
 9 root@localhost:mysql3306.sock [zlm]05:36:10>create procedure pro_flashbk()
10     -> begin
11     -> declare id int;
12     -> set id = 100000;
13     -> while id>0 do
14     -> insert into test_flashbk(name) values ('aaron8219');  
15     -> set id=id-1;
16     -> end while;
17     -> end //
18 Query OK, 0 rows affected (0.04 sec)
19  
20 root@localhost:mysql3306.sock [zlm]05:36:11>delimiter ;
21 root@localhost:mysql3306.sock [zlm]05:36:23>call pro_flashbk();
22 Query OK, 1 row affected (11.06 sec)
23  
24 root@localhost:mysql3306.sock [zlm]05:36:41>select count(*) from test_flashbk;
25 +----------+
26 | count(*) |
27 +----------+
28 |   100000 |
29 +----------+
30 1 row in set (0.02 sec)
31  
32 root@localhost:mysql3306.sock [zlm]05:37:17>select id,name from test_flashbk limit 0,5;
33 +----+-----------+
34 | id | name      |
35 +----+-----------+
36 |  1 | aaron8219 |
37 |  2 | aaron8219 |
38 |  3 | aaron8219 |
39 |  4 | aaron8219 |
40 |  5 | aaron8219 |
41 +----+-----------+
42 5 rows in set (0.00 sec)
43  
44 root@localhost:mysql3306.sock [zlm]05:38:04>select @@autocommit;
45 +--------------+
46 | @@autocommit |
47 +--------------+
48 |            1 |
49 +--------------+
50 1 row in set (0.03 sec)
51  
52 root@localhost:mysql3306.sock [zlm]05:38:12>

secondly,let's mimic the situation about updating records without using "where clause",after that the operation will update all the records in the test table "test_flashbk":

 1 root@localhost:mysql3306.sock [zlm]05:38:12>update test_flashbk set name='zlm';
 2 Query OK, 100000 rows affected (2.29 sec)
 3 Rows matched: 100000  Changed: 100000  Warnings: 0
 4  
 5 root@localhost:mysql3306.sock [zlm]05:39:00>select id,name from test_flashbk limit 0,5;
 6 +----+------+
 7 | id | name |
 8 +----+------+
 9 |  1 | zlm  |
10 |  2 | zlm  |
11 |  3 | zlm  |
12 |  4 | zlm  |
13 |  5 | zlm  |
14 +----+------+
15 5 rows in set (0.00 sec)
16  
17 root@localhost:mysql3306.sock [zlm]05:39:09>show binary logs;
18 +------------------+-----------+
19 | Log_name         | File_size |
20 +------------------+-----------+
21 | mysql-bin.000013 |       217 |
22 | mysql-bin.000014 |      1341 |
23 | mysql-bin.000015 |       217 |
24 | mysql-bin.000016 |       680 |
25 | mysql-bin.000017 | 268435617 |
26 | mysql-bin.000018 |  72724124 |
27 +------------------+-----------+
28 8 rows in set (0.04 sec)
29  
30 root@localhost:mysql3306.sock [zlm]05:39:26>exit
31 Bye
32  
33 [root@zlm1 17:40:34 ~]
34 #cd /data/mysql/mysql3306/logs
35  
36 [root@zlm1 17:40:50 /data/mysql/mysql3306/logs]
37 #ls -l
38 total 368408
39 -rw-r----- 1 mysql mysql       217 May 26 15:37 mysql-bin.000013
40 -rw-r----- 1 mysql mysql      1341 May 26 22:24 mysql-bin.000014
41 -rw-r----- 1 mysql mysql       217 May 26 22:24 mysql-bin.000015
42 -rw-r----- 1 mysql mysql       680 May 30 21:22 mysql-bin.000016
43 -rw-r----- 1 mysql mysql 268435617 Jun  1 16:57 mysql-bin.000017
44 -rw-r----- 1 mysql mysql  72724124 Jun  1 17:39 mysql-bin.000018
45 -rw-r----- 1 mysql mysql       264 Jun  1 16:57 mysql-bin.index
46  
47 [root@zlm1 17:40:53 /data/mysql/mysql3306/logs]
50 #

now,let's using the MyFlash tool to flashback the correct data.you should notice that only one binary log can be put in the parameter "binlogFileNames".it cannot be too big up to 256M,'cauze in my early case,i put 100w records into the test table at the begining,the operation was killed by OS automatically twice,it's amazing...sometime i'll test it again to find out the real reason for that.

 1 [root@zlm1 18:01:21 ~]
 2 #cd /vagrant/MyFlash-master/binary/
 3  
 4 [root@zlm1 18:02:50 /vagrant/MyFlash-master/binary]
 5 #ls -l
 6 total 7366
 7 -rwxrwxrwx 1 vagrant vagrant   78542 Oct 25  2017 flashback
 8 -rwxrwxrwx 1 vagrant vagrant 7463125 Oct 25  2017 mysqlbinlog20160408
 9  
10 [root@zlm1 18:02:51 /vagrant/MyFlash-master/binary]
11 #./flashback --databaseNames zlm --tableNames test_flashbk --sqlTypes update  --maxSplitSize=10 --binlogFileNames=/data/mysql/mysql3306/logs/mysql-bin.000018
12  
13 [root@zlm1 18:03:15 /vagrant/MyFlash-master/binary]
14 #ls -l
15 total 78628
16 -rwxrwxrwx 1 vagrant vagrant 10491131 Jun  1 18:03 binlog_output_base.000001
17 -rwxrwxrwx 1 vagrant vagrant 10489686 Jun  1 18:03 binlog_output_base.000002
18 -rwxrwxrwx 1 vagrant vagrant 10489686 Jun  1 18:03 binlog_output_base.000003
19 -rwxrwxrwx 1 vagrant vagrant 10485809 Jun  1 18:03 binlog_output_base.000004
20 -rwxrwxrwx 1 vagrant vagrant 10486005 Jun  1 18:03 binlog_output_base.000005
21 -rwxrwxrwx 1 vagrant vagrant 10486005 Jun  1 18:03 binlog_output_base.000006
22 -rwxrwxrwx 1 vagrant vagrant 10042310 Jun  1 18:03 binlog_output_base.000007
23 -rwxrwxrwx 1 vagrant vagrant    78542 Oct 25  2017 flashback
24 -rwxrwxrwx 1 vagrant vagrant  7463125 Oct 25  2017 mysqlbinlog20160408
25  
26 [root@zlm1 18:03:19 /vagrant/MyFlash-master/binary]
27 #

here,i used the parameter "maxSplitSize" to split the output flashback file into 7 files，each one became 10M around.after that,i try to recover the data by the shell script below,unfortunately it failed:

 1 [root@zlm1 18:37:00 ~]
 2 #cat > recover.sh <<aaron8219
 3 > #!/bin/bash
 4 > BASEDIR=/vagrant/MyFlash-master/binary
 5 > FILE=\`find \${BASEDIR} -name "binlog_output_base.00000*"|sort -n\`
 6 > for i in \${FILE}
 7 > do
 8 >   mysqlbinlog \${i} | mysql
 9 > done
10 > aaron8219
11  
12 [root@zlm1 18:37:03 ~]
13 #cat recover.sh 
14 #!/bin/bash
15 BASEDIR=/vagrant/MyFlash-master/binary
16 FILE=`find ${BASEDIR} -name "binlog_output_base.00000*"|sort -n`
17 for i in ${FILE}
18 do
19   mysqlbinlog ${i} | mysql
20 done
21  
22 [root@zlm1 18:37:09 ~]
23 #ls -l
24 total 16
25 -rw-------. 1 root root 1431 Jul 16  2015 anaconda-ks.cfg
26 -rwxr-xr-x  1 root root   59 Apr  2 14:29 mysqld.sh
27 -rwxr-xr-x  1 root root   40 Jun  1 16:13 mysql.sh
28 -rw-r--r--  1 root root  168 Jun  1 18:37 recover.sh
29 -rw-r--r--  1 root root    0 May 30 20:33 rename_tb.sql
30  
31 [root@zlm1 18:37:12 ~]
32 #sh recover.sh
33 ERROR 1782 (HY000) at line 17: @@SESSION.GTID_NEXT cannot be set to ANONYMOUS when @@GLOBAL.GTID_MODE = ON.
34 ERROR 1782 (HY000) at line 17: @@SESSION.GTID_NEXT cannot be set to ANONYMOUS when @@GLOBAL.GTID_MODE = ON.
35 ERROR 1782 (HY000) at line 17: @@SESSION.GTID_NEXT cannot be set to ANONYMOUS when @@GLOBAL.GTID_MODE = ON.
36 ERROR 1782 (HY000) at line 14: @@SESSION.GTID_NEXT cannot be set to ANONYMOUS when @@GLOBAL.GTID_MODE = ON.
37 ERROR 1782 (HY000) at line 14: @@SESSION.GTID_NEXT cannot be set to ANONYMOUS when @@GLOBAL.GTID_MODE = ON.
38 ERROR 1782 (HY000) at line 14: @@SESSION.GTID_NEXT cannot be set to ANONYMOUS when @@GLOBAL.GTID_MODE = ON.

https://bugs.mysql.com/bug.php?id=85480 this website reported the bug on 5.7.17,but mine is 5.7.21

Bug #85480	@@SESSION.GTID_NEXT cannot be set to ANONYMOUS when @@GLOBAL.GTID_MODE = ON
Submitted:	16 Mar 2017 12:01	Modified:	26 Mar 2017 19:04
Reporter:	kfpanda kf	Email Updates:
Status:	Verified	Impact on me:	None
Category:	MySQL Server: Replication	Severity:	S3 (Non-critical)
Version:	5.7.17	OS:	Any
Assigned to:		CPU Architecture:	Any

[16 Mar 2017 12:01] kfpanda kf

Description:
mysqlbinlog printed a ROLLBACK at the end of the binary log
    file, which when played back caused the error
    -@@SESSION.GTID_NEXT cannot be set to ANONYMOUS when
    @@GLOBAL.GTID_MODE = ON..- This occurred when the binary log file
    did not include any data related events.

How to repeat: Generate a binary log file which did not include any data related events. mysql -uroot -p123456 mysql> show binary logs; +------------------+-----------+ | Log_name | File_size | +------------------+-----------+ | mysql-bin.000001 | 177 | | mysql-bin.000002 | 201 | +------------------+-----------+ mysql> flush logs; mysql> flush logs; +------------------+-----------+ | Log_name | File_size | +------------------+-----------+ | mysql-bin.000001 | 177 | | mysql-bin.000002 | 201 | | mysql-bin.000003 | 201 | | mysql-bin.000004 | 201 | +------------------+-----------+ # mysqlbinlog mysql-bin.000003|mysql -uroot -p'123456' mysql: [Warning] Using a password on the command line interface can be insecure. ERROR 1782 (HY000) at line 19: @@SESSION.GTID_NEXT cannot be set to ANONYMOUS when @@GLOBAL.GTID_MODE = ON. Suggested fix: stops a ROLLBACK from setting gtid_next to ANONYMOUS when gtid_next has not yet been determined by a subsequent event.

 1 root@localhost:mysql3306.sock [(none)]07:00:32>select @@global.gtid_next;
 2 ERROR 1238 (HY000): Variable 'gtid_next' is a SESSION variable
 3 root@localhost:mysql3306.sock [(none)]07:00:52>select @@gtid_next;
 4 +-------------+
 5 | @@gtid_next |
 6 +-------------+
 7 | AUTOMATIC   |
 8 +-------------+
 9 1 row in set (0.00 sec)
10  
11 root@localhost:mysql3306.sock [(none)]07:00:58>

it seems not the bug issue.on the other hand,the description about GTID_MODE in official document was described as below:

GTID

The GTID column contains the value of gtid_next, which can be one of ANONYMOUS, AUTOMATIC, or a GTID using the formatUUID:NUMBER. For transactions that use gtid_next=AUTOMATIC, which is all normal client transactions, the GTID column changes when the transaction commits and the actual GTID is assigned. If gtid_mode is either ON or ON_PERMISSIVE, the GTID column changes to the transaction's GTID. If gtid_mode is either OFF or OFF_PERMISSIVE, the GTID column changes to ANONYMOUS.

来源： https://dev.mysql.com/doc/refman/5.7/en/events-transactions-current-table.html

now i try to set gtid_mode=off_permissive step by step:

 1 [root@zlm1 18:37:26 ~]
 2 #mysql
 3 Welcome to the MySQL monitor.  Commands end with ; or \g.
 4 Your MySQL connection id is 17
 5 Server version: 5.7.21-log MySQL Community Server (GPL)
 6  
 7 Copyright (c) 2000, 2018, Oracle and/or its affiliates. All rights reserved.
 8  
 9 Oracle is a registered trademark of Oracle Corporation and/or its
10 affiliates. Other names may be trademarks of their respective
11 owners.
12  
13 Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.
14  
15 root@localhost:mysql3306.sock [(none)]06:45:01>select @@global.gtid_mode;
16 +--------------------+
17 | @@global.gtid_mode |
18 +--------------------+
19 | ON                 |
20 +--------------------+
21 1 row in set (0.00 sec)
22  
23 root@localhost:mysql3306.sock [(none)]06:45:32>set @@global.gtid_mode=off_permissive;
24 ERROR 1788 (HY000): The value of @@GLOBAL.GTID_MODE can only be changed one step at a time: OFF <-> OFF_PERMISSIVE <-> ON_PERMISSIVE <-> ON. Also note that this value must be stepped up or down simultaneously on all servers. See the Manual for instructions.
25 root@localhost:mysql3306.sock [(none)]06:53:22>select @@global.gtid_mode;
26 +--------------------+
27 | @@global.gtid_mode |
28 +--------------------+
29 | ON_PERMISSIVE      |
30 +--------------------+
31 1 row in set (0.00 sec)
32  
33 root@localhost:mysql3306.sock [(none)]06:53:35>set @@global.gtid_mode=off_permissive;
34 Query OK, 0 rows affected (0.01 sec)
35  
36 root@localhost:mysql3306.sock [(none)]06:53:51>select @@global.gtid_mode;
37 +--------------------+
38 | @@global.gtid_mode |
39 +--------------------+
40 | OFF_PERMISSIVE     |
41 +--------------------+
42 1 row in set (0.00 sec)
43  
44 root@localhost:mysql3306.sock [(none)]06:54:01>exit
45  
46  
47 Bye

it failed again with ERROR 1032，cant't find record in table:

1 [root@zlm1 19:07:01 ~]
2 #sh recover.sh 
3  
4 ERROR 1032 (HY000) at line 42577: Can't find record in 'test_flashbk'
5 ERROR 1032 (HY000) at line 17: Can't find record in 'test_flashbk'
6 ERROR 1032 (HY000) at line 17: Can't find record in 'test_flashbk'

then i modify the shell script file add "--skip-gtids" but it still not work normally,this time,i even got the ERROR 1062 excepts the ERROR 1032:

 1 [root@zlm1 20:17:48 ~]
 2 #vi recover.sh 
 3 
 4 [root@zlm1 20:18:04 ~]
 5 #cat recover.sh 
 6 #!/bin/bash
 7 BASEDIR=/vagrant/MyFlash-master/binary
 8 FILE=`find ${BASEDIR} -name "binlog_output_base.00000*"|sort -n`
 9 for i in ${FILE}
10 do
11   mysqlbinlog --skip-gtids ${i} | mysql
12 done
13 
14 [root@zlm1 20:18:08 ~]
15 #sh recover.sh
16 ERROR 1032 (HY000) at line 42578: Can't find record in 'test_flashbk'
17 ERROR 1032 (HY000) at line 18: Can't find record in 'test_flashbk'
18 ERROR 1032 (HY000) at line 18: Can't find record in 'test_flashbk'
19 ERROR 1062 (23000) at line 35: Duplicate entry '83' for key 'PRIMARY'
20 ERROR 1062 (23000) at line 35: Duplicate entry '37802' for key 'PRIMARY'
21 ERROR 1062 (23000) at line 35: Duplicate entry '75521' for key 'PRIMARY'
22 
23 [root@zlm1 20:18:28 ~]
24 #

now,i have no idea about how to solve the issue.it seems not so convenient to flashback the incorrect data back to the original state with the MyFlash tool,it still has some defect,restriction and so forth,hope it will be enhensed in the future release.