In case of Database Recovery after unexpected data corruption, list some commonly used scenarios of mysqlbinlog for processing binary log files.

Display Row Events

Convert binary events to SQL statements, DDL output will be displayed as a raw statement, DML output will be presented as lines beginning with ###, those are “pseudo-SQL” statements which are not executable.

For DML pseudo-SQL statements, they do not correspond exactly to the original SQL statements that generated the events, The original column names are lost and replaced by @*N*, where N is a column number.

Also if you are using multi-character set data, those character set information is not available in the display.

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
$ mysqlbinlog --base64-output=decode-rows -v mysql-bin.000008
...
# at 347
#180412 9:52:43 server id 231144 end_log_pos 395 CRC32 0x84460ead GTID [commit=yes]
SET @@SESSION.GTID_NEXT= '951e9bca-204f-11e8-b037-0127be441dc2:195'/*!*/;
# at 395
#180412 9:52:43 server id 231144 end_log_pos 495 CRC32 0x439d8a47 Query thread_id=69 exec_time=0 error_code=0
SET TIMESTAMP=1523497963/*!*/;
create database ghtest
/*!*/;
# at 495
#180412 9:52:43 server id 231144 end_log_pos 543 CRC32 0x01f37d7c GTID [commit=yes]
SET @@SESSION.GTID_NEXT= '951e9bca-204f-11e8-b037-0127be441dc2:196'/*!*/;
# at 543
#180412 9:52:43 server id 231144 end_log_pos 727 CRC32 0xd55dfb81 Query thread_id=69 exec_time=0 error_code=0
use `ghtest`/*!*/;
SET TIMESTAMP=1523497963/*!*/;
create table gh_ost_test (
id int auto_increment,
i int not null,
primary key(id)
) auto_increment=1
/*!*/;
...
# at 727
#180412 9:52:43 server id 231144 end_log_pos 775 CRC32 0x68785572 GTID [commit=yes]
SET @@SESSION.GTID_NEXT= '951e9bca-204f-11e8-b037-0127be441dc2:197'/*!*/;
# at 775
#180412 9:52:43 server id 231144 end_log_pos 849 CRC32 0xc2c7a477 Query thread_id=69 exec_time=0 error_code=0
SET TIMESTAMP=1523497963/*!*/;
BEGIN
/*!*/;
# at 849
#180412 9:52:43 server id 231144 end_log_pos 906 CRC32 0x77d59f8e Table_map: `ghtest`.`gh_ost_test` mapped to number 75
# at 906
#180412 9:52:43 server id 231144 end_log_pos 950 CRC32 0x731168d0 Write_rows: table id 75 flags: STMT_END_F
### INSERT INTO `ghtest`.`gh_ost_test`
### SET
### @1=1
### @2=0
# at 950
#180412 9:52:43 server id 231144 end_log_pos 981 CRC32 0xc7f39dd9 Xid = 253
COMMIT/*!*/;

Redo BINLOG Changes

It’s useful for recovery operations by re-executing the output generated by mysqlbinlog, aka Point-in-Time (Incremental) Recovery. Rewrite the command in the last section to generate mysqlbinlog output with BINLOG statements. Each BINLOG statement contains a base 64-encoded string that server decodes to determine the data change indicated by the corresponding event. It requires the SUPER privilege.

Some pratices below:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
# Output with BINLOG statements
$ mysqlbinlog --base64-output=auto -v mysql-bin.000008
...
# at 495
#180412 9:52:43 server id 231144 end_log_pos 543 CRC32 0x01f37d7c GTID [commit=yes]
SET @@SESSION.GTID_NEXT= '951e9bca-204f-11e8-b037-0127be441dc2:196'/*!*/;
# at 543
#180412 9:52:43 server id 231144 end_log_pos 727 CRC32 0xd55dfb81 Query thread_id=69 exec_time=0 error_code=0
use `ghtest`/*!*/;
SET TIMESTAMP=1523497963/*!*/;
create table gh_ost_test (
id int auto_increment,
i int not null,
primary key(id)
) auto_increment=1
/*!*/;
# at 727
#180412 9:52:43 server id 231144 end_log_pos 775 CRC32 0x68785572 GTID [commit=yes]
SET @@SESSION.GTID_NEXT= '951e9bca-204f-11e8-b037-0127be441dc2:197'/*!*/;
# at 775
#180412 9:52:43 server id 231144 end_log_pos 849 CRC32 0xc2c7a477 Query thread_id=69 exec_time=0 error_code=0
SET TIMESTAMP=1523497963/*!*/;
BEGIN
/*!*/;
# at 849
#180412 9:52:43 server id 231144 end_log_pos 906 CRC32 0x77d59f8e Table_map: `ghtest`.`gh_ost_test` mapped to number 75
# at 906
#180412 9:52:43 server id 231144 end_log_pos 950 CRC32 0x731168d0 Write_rows: table id 75 flags: STMT_END_F
BINLOG '
67vOWhPohgMAOQAAAIoDAAAAAEsAAAAAAAEABmdodGVzdAALZ2hfb3N0X3Rlc3QAAgMDAACOn9V3
67vOWh7ohgMALAAAALYDAAAAAEsAAAAAAAEAAgAC//wBAAAAAAAAANBoEXM=
'/*!*/;
### INSERT INTO `ghtest`.`gh_ost_test`
### SET
### @1=1
### @2=0
# at 950
#180412 9:52:43 server id 231144 end_log_pos 981 CRC32 0xc7f39dd9 Xid = 253
COMMIT/*!*/;
...
# write binary log to a single file and then process the file
$ mysqlbinlog --base64-output=auto -v --start-position=2302 mysql-bin.000008 | grep -v "SESSION.GTID_NEXT" > /tmp/mysql-bin-xxx.sql
# If the statements produced by mysqlbinlog may contain BLOB values, these may cause problems when mysql processes them. In this case, invoke mysql with the --binary-mode option.
$ mysql -u xxx -pxxx < /tmp/mysql-bin-xxx.sql
# extract changes of a specific GTID range
$ mysqlbinlog --base64-output=decode-rows -v --include-gtids=951e9bca-204f-11e8-b037-0127be441dc2:1-203 mysql-bin.000008

Please note that I suppressed all SET SESSION.GTID_NEXT statements to make GTID generate automatically, alternatively you can reserve GTID_NEXT info and process them on another instance to make GTID changes exactly same as the instance the binary logs belong, like a replication client.

Extract SQL Statements

Sometimes we need to extract the SQL statements as a source file, make changes on some sqls and then process on another instance. there isn’t a built-in way to perform that operation, a workaround as follows and we should extract :

  1. Get pseudo-SQL output by providing –base64-output=decode-row -v options
  2. Replace @N with their original column names
  3. Remove all the ### prefix of the statements

Here is an example of extracting sqls from a specific table:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
$ mysqlbinlog --base64-output=decode-rows -v mysql-bin.000008 |
sed -e 's/### @1/ id/' -e 's/### @2/, i/' |
sed -e 's/### //g' |
sed '/i=[0-9]*/s//&;/' |
sed -e '/^#/d' -e '/^--$/d'
...
drop database if exists ghtest
/*!*/;
SET @@SESSION.GTID_NEXT= '951e9bca-204f-11e8-b037-0127be441dc2:195'/*!*/;
SET TIMESTAMP=1523497963/*!*/;
create database ghtest
/*!*/;
SET @@SESSION.GTID_NEXT= '951e9bca-204f-11e8-b037-0127be441dc2:196'/*!*/;
use `ghtest`/*!*/;
SET TIMESTAMP=1523497963/*!*/;
create table gh_ost_test (
id int auto_increment,
i int not null,
primary key(id)
) auto_increment=1
/*!*/;
SET @@SESSION.GTID_NEXT= '951e9bca-204f-11e8-b037-0127be441dc2:197'/*!*/;
SET TIMESTAMP=1523497963/*!*/;
BEGIN
/*!*/;
INSERT INTO `ghtest`.`gh_ost_test`
SET
id=1
, i=0;
COMMIT/*!*/;
...

Generate Rollback SQL

Like talking on *Extract SQL Statements* section, if you want to reverse SQL on binary log files, we have to handle it by cases instead of generating them directly, at least not an easy way to do that now.

However, by the time we need to perform this operation, there’re approaches we can do after the SQL statements been extracted.

  1. Extract SQL Statement
  2. replace different DML type for reversing

Some examples:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
# reverse INSERT events
$ mysqlbinlog --base64-output=decode-rows -v mysql-bin.000010
...
BEGIN
/*!*/;
# at 313
#180413 13:30:31 server id 231144 end_log_pos 371 CRC32 0x5f85e3c7 Table_map: `ghtest`.`gh_ost_test` mapped to number 78
# at 371
#180413 13:30:31 server id 231144 end_log_pos 419 CRC32 0x436c5ecf Write_rows: table id 78 flags: STMT_END_F
### INSERT INTO `ghtest`.`gh_ost_test`
### SET
### @1=6
### @2=0
# at 419
#180413 13:30:31 server id 231144 end_log_pos 450 CRC32 0x2f186b8b Xid = 694
COMMIT/*!*/;
...
$ mysqlbinlog --base64-output=decode-rows -v mysql-bin.000010 | grep -A 4 '### INSERT INTO' |
sed -e 's/### INSERT INTO/DELETE FROM/' -e 's/### SET/WHERE/' |
sed -e 's/### @1/ id/' -e 's/### @2/, i/' |
sed '/i=[0-9]*/s//&;/'
DELETE FROM `ghtest`.`gh_ost_test`
WHERE
id=6
, i=0;
# Reverse DELETE events
$ mysqlbinlog --base64-output=decode-rows -v mysql-bin.000010 | grep -A 4 '### DELETE FROM' |
sed -e 's/### DELETE FROM/INSERT INTO/' -e 's/### WHERE/SET/'|
sed -e 's/### @1/ id/' -e 's/### @2/, i/' |
sed '/i=[0-9]*/s//&;/'
INSERT INTO `ghtest`.`gh_ost_test`
SET
id=4
, i=1;
# Reverse UPDATE events
$ mysqlbinlog --base64-output=decode-rows -v mysql-bin.000010
...
# at 498
#180413 13:30:47 server id 231144 end_log_pos 572 CRC32 0x002c4eae Query thread_id=80 exec_time=0 error_code=0
SET TIMESTAMP=1523597447/*!*/;
BEGIN
/*!*/;
# at 572
#180413 13:30:47 server id 231144 end_log_pos 630 CRC32 0x1ec396c8 Table_map: `ghtest`.`gh_ost_test` mapped to number 78
# at 630
#180413 13:30:47 server id 231144 end_log_pos 692 CRC32 0x8a24569e Update_rows: table id 78 flags: STMT_END_F
### UPDATE `ghtest`.`gh_ost_test`
### WHERE
### @1=3
### @2=2
### SET
### @1=3
### @2=3
# at 692
#180413 13:30:47 server id 231144 end_log_pos 723 CRC32 0x7bcddc40 Xid = 695
COMMIT/*!*/;
...
$ mysqlbinlog --base64-output=decode-rows -v mysql-bin.000010 | grep -A 8 '### UPDATE' |
sed -e 's/### UPDATE/UPDATE/' | sed -e 's/### SET/WHERE/' | sed -e 's/### WHERE/SET/' |
sed -e 's/### @1/ id/' -e 's/### @2/, i/' |
sed -e '/WHERE/{n;n;s|$|;|}'
...
UPDATE `ghtest`.`gh_ost_test`
SET
id=3
, i=2
WHERE
id=3
, i=3;
...

Reference

https://dev.mysql.com/doc/refman/5.6/en/mysqlbinlog.html

https://dev.mysql.com/doc/refman/5.6/en/mysqlbinlog-row-events.html

https://dev.mysql.com/doc/refman/5.6/en/point-in-time-recovery.html

https://dev.mysql.com/doc/refman/5.6/en/mysqlbinlog-backup.html