mysqlbinlog可以使用start-datetime/stop-datetime选取某个时间段内的日志,或者start-position/stop-position选取某个log_pos范围内的日志。这一点可以用来做Point-in-Time recovery。
假定以下场景:在某个时刻,不小心插入了一条'name4'的记录,需要使用原来的备份+binary log实现Point-in-Time recovery
mysql> CREATE TABLE `B` ( `col1` char(15) DEFAULT NULL, `col2` timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP);
shell> mysqldump -h localhost -u root -pqingsong test1 > test1.sql
mysql> reset master;
mysql> insert into B values('name1', default);
mysql> insert into B values('name2', default);
mysql> insert into B values('name3', default);
mysql> insert into B values('name4', default); <--误操作,本不想插入这条数据的
mysql> insert into B values('name5', default);
mysql> select * from B;
+-------+---------------------+
| col1 | col2 |
+-------+---------------------+
| name1 | 2017-08-08 09:01:48 |
| name2 | 2017-08-08 09:01:53 |
| name3 | 2017-08-08 09:01:58 |
| name4 | 2017-08-08 09:02:03 |
| name5 | 2017-08-08 09:02:12 |
+-------+---------------------+
5 rows in set (0.00 sec)
shell> mysqlbinlog /var/log/mysql/binerr.000001 > full
shell> mysqlbinlog --stop-datetime="2017-08-08 09:01:58" /var/log/mysql/binerr.000001 > part1
shell> mysqlbinlog --start-datetime="2017-08-08 09:01:58" /var/log/mysql/binerr.000001 > part2
shell> mysqlbinlog --start-datetime="2017-08-08 09:01:53" --stop-datetime="2017-08-08 09:02:03" /var/log/mysql/binerr.000001 > part3
full文件里包含了所有5条insert操作
root@db2a:~# grep -i 'name[1-9]' -B 3 full | grep -iv -e 'SET TIMESTAMP' -e '^# at'
#170808 9:01:48 server id 1 end_log_pos 414 CRC32 0xbcd4fbfc Query thread_id=4 exec_time=0 error_code=0
use `test1`/*!*/;
insert into B values('name1', default)
--
#170808 9:01:53 server id 1 end_log_pos 705 CRC32 0x0521172a Query thread_id=4 exec_time=0 error_code=0
insert into B values('name2', default)
--
#170808 9:01:58 server id 1 end_log_pos 996 CRC32 0xe6269ccf Query thread_id=4 exec_time=0 error_code=0
insert into B values('name3', default)
--
#170808 9:02:03 server id 1 end_log_pos 1287 CRC32 0xc7bff093 Query thread_id=4 exec_time=0 error_code=0
insert into B values('name4', default)
--
#170808 9:02:12 server id 1 end_log_pos 1578 CRC32 0x70d29d1e Query thread_id=4 exec_time=0 error_code=0
insert into B values('name5', default)
指定stop-datetime="2017-08-08 09:01:58"时,只读取了前两条记录:
root@db2a:~# grep -i 'name[1-9]' -B 3 part1 | grep -iv -e 'SET TIMESTAMP' -e '^# at'
#170808 9:01:48 server id 1 end_log_pos 414 CRC32 0xbcd4fbfc Query thread_id=4 exec_time=0 error_code=0
use `test1`/*!*/;
insert into B values('name1', default)
--
#170808 9:01:53 server id 1 end_log_pos 705 CRC32 0x0521172a Query thread_id=4 exec_time=0 error_code=0
insert into B values('name2', default)
指定-start-datetime="2017-08-08 09:01:58" 时,读取了后三条记录:
root@db2a:~# grep -i 'name[1-9]' -B 3 part2 | grep -iv -e 'SET TIMESTAMP' -e '^# at'
#170808 9:01:58 server id 1 end_log_pos 996 CRC32 0xe6269ccf Query thread_id=4 exec_time=0 error_code=0
use `test1`/*!*/;
insert into B values('name3', default)
--
#170808 9:02:03 server id 1 end_log_pos 1287 CRC32 0xc7bff093 Query thread_id=4 exec_time=0 error_code=0
insert into B values('name4', default)
--
#170808 9:02:12 server id 1 end_log_pos 1578 CRC32 0x70d29d1e Query thread_id=4 exec_time=0 error_code=0
insert into B values('name5', default)
指定"2017-08-08 09:01:53"到"2017-08-08 09:02:03"之间时,只有两条记录:
root@db2a:~# grep -i 'name[1-9]' -B 3 part3 | grep -iv -e 'SET TIMESTAMP' -e '^# at'
#170808 9:01:53 server id 1 end_log_pos 705 CRC32 0x0521172a Query thread_id=4 exec_time=0 error_code=0
use `test1`/*!*/;
insert into B values('name2', default)
--
#170808 9:01:58 server id 1 end_log_pos 996 CRC32 0xe6269ccf Query thread_id=4 exec_time=0 error_code=0
insert into B values('name3', default)
由上面可以看到start time是闭区间,而stop time是开区间,即[start-datetime, stop-datetime), 如果指定stop-datetime="2017-08-08 09:01:58",实际上读取到"2017-08-08 09:01:57"
shell> mysqladmin -pqingsong flush-logs
shell> mysql -h localhost -u root -pqingsong test1 < test1.sql
2.2 恢复到name3
由于name4的插入时间为2017-08-08 09:02:03,加上stop-datetime是开区间,所以指定到这个时间即可:
shell> mysqlbinlog --stop-datetime="2017-08-08 09:02:03" /var/log/mysql/binerr.000001 | mysql -h localhost -u root -pqingsong test1
mysql> select * from B;
+-------+---------------------+
| col1 | col2 |
+-------+---------------------+
| name1 | 2017-08-08 09:01:48 |
| name2 | 2017-08-08 09:01:53 |
| name3 | 2017-08-08 09:01:58 |
+-------+---------------------+
3 rows in set (0.00 sec)
2.3 跳过name4
从name4的插入时间"2017-08-08 09:02:03"的下一秒开始:
shell> mysqlbinlog --start-datetime="2017-08-08 09:02:04" /var/log/mysql/binerr.000001 | mysql -h localhost -u root -pqingsong test1
mysql> select * from B;
+-------+---------------------+
| col1 | col2 |
+-------+---------------------+
| name1 | 2017-08-08 09:01:48 |
| name2 | 2017-08-08 09:01:53 |
| name3 | 2017-08-08 09:01:58 |
| name5 | 2017-08-08 09:02:12 |
+-------+---------------------+
4 rows in set (0.00 sec)
shell> grep -i 'name[1-9]' -B 3 full | grep -iv -e 'SET TIMESTAMP'
#170808 9:01:48 server id 1 end_log_pos 414 CRC32 0xbcd4fbfc Query thread_id=4 exec_time=0 error_code=0
use `test1`/*!*/;
insert into B values('name1', default)
--
# at 591
#170808 9:01:53 server id 1 end_log_pos 705 CRC32 0x0521172a Query thread_id=4 exec_time=0 error_code=0
insert into B values('name2', default)
--
# at 882
#170808 9:01:58 server id 1 end_log_pos 996 CRC32 0xe6269ccf Query thread_id=4 exec_time=0 error_code=0
insert into B values('name3', default)
--
# at 1173
#170808 9:02:03 server id 1 end_log_pos 1287 CRC32 0xc7bff093 Query thread_id=4 exec_time=0 error_code=0
insert into B values('name4', default)
--
# at 1464
#170808 9:02:12 server id 1 end_log_pos 1578 CRC32 0x70d29d1e Query thread_id=4 exec_time=0 error_code=0
insert into B values('name5', default)
'name4'的start position是1173, 它下一个操作的start position是1287,所以,Point-in-Time recovery的时候,先做到1173,再从1287开始做,这样就跳过了'name4'
(这里的stop-position仍然是开区间)
shell> mysql -h localhost -u root -pqingsong test1 < test1.sql
shell> mysqlbinlog --stop-position=1173 /var/log/mysql/binerr.000001 | mysql -h localhost -u root -pqingsong test1
shell> mysqlbinlog --start-position=1287 /var/log/mysql/binerr.000001 | mysql -h localhost -u root -pqingsong test1
shell> mysqlbinlog binlog.000001 > /tmp/statements.sql
shell> mysqlbinlog binlog.000002 >> /tmp/statements.sql
假定以下场景:在某个时刻,不小心插入了一条'name4'的记录,需要使用原来的备份+binary log实现Point-in-Time recovery
mysql> CREATE TABLE `B` ( `col1` char(15) DEFAULT NULL, `col2` timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP);
shell> mysqldump -h localhost -u root -pqingsong test1 > test1.sql
mysql> reset master;
mysql> insert into B values('name1', default);
mysql> insert into B values('name2', default);
mysql> insert into B values('name3', default);
mysql> insert into B values('name4', default); <--误操作,本不想插入这条数据的
mysql> insert into B values('name5', default);
mysql> select * from B;
+-------+---------------------+
| col1 | col2 |
+-------+---------------------+
| name1 | 2017-08-08 09:01:48 |
| name2 | 2017-08-08 09:01:53 |
| name3 | 2017-08-08 09:01:58 |
| name4 | 2017-08-08 09:02:03 |
| name5 | 2017-08-08 09:02:12 |
+-------+---------------------+
5 rows in set (0.00 sec)
1. 熟悉start-datetime/stop-datetime参数
先按照时间段读取binary log:shell> mysqlbinlog /var/log/mysql/binerr.000001 > full
shell> mysqlbinlog --stop-datetime="2017-08-08 09:01:58" /var/log/mysql/binerr.000001 > part1
shell> mysqlbinlog --start-datetime="2017-08-08 09:01:58" /var/log/mysql/binerr.000001 > part2
shell> mysqlbinlog --start-datetime="2017-08-08 09:01:53" --stop-datetime="2017-08-08 09:02:03" /var/log/mysql/binerr.000001 > part3
full文件里包含了所有5条insert操作
root@db2a:~# grep -i 'name[1-9]' -B 3 full | grep -iv -e 'SET TIMESTAMP' -e '^# at'
#170808 9:01:48 server id 1 end_log_pos 414 CRC32 0xbcd4fbfc Query thread_id=4 exec_time=0 error_code=0
use `test1`/*!*/;
insert into B values('name1', default)
--
#170808 9:01:53 server id 1 end_log_pos 705 CRC32 0x0521172a Query thread_id=4 exec_time=0 error_code=0
insert into B values('name2', default)
--
#170808 9:01:58 server id 1 end_log_pos 996 CRC32 0xe6269ccf Query thread_id=4 exec_time=0 error_code=0
insert into B values('name3', default)
--
#170808 9:02:03 server id 1 end_log_pos 1287 CRC32 0xc7bff093 Query thread_id=4 exec_time=0 error_code=0
insert into B values('name4', default)
--
#170808 9:02:12 server id 1 end_log_pos 1578 CRC32 0x70d29d1e Query thread_id=4 exec_time=0 error_code=0
insert into B values('name5', default)
指定stop-datetime="2017-08-08 09:01:58"时,只读取了前两条记录:
root@db2a:~# grep -i 'name[1-9]' -B 3 part1 | grep -iv -e 'SET TIMESTAMP' -e '^# at'
#170808 9:01:48 server id 1 end_log_pos 414 CRC32 0xbcd4fbfc Query thread_id=4 exec_time=0 error_code=0
use `test1`/*!*/;
insert into B values('name1', default)
--
#170808 9:01:53 server id 1 end_log_pos 705 CRC32 0x0521172a Query thread_id=4 exec_time=0 error_code=0
insert into B values('name2', default)
指定-start-datetime="2017-08-08 09:01:58" 时,读取了后三条记录:
root@db2a:~# grep -i 'name[1-9]' -B 3 part2 | grep -iv -e 'SET TIMESTAMP' -e '^# at'
#170808 9:01:58 server id 1 end_log_pos 996 CRC32 0xe6269ccf Query thread_id=4 exec_time=0 error_code=0
use `test1`/*!*/;
insert into B values('name3', default)
--
#170808 9:02:03 server id 1 end_log_pos 1287 CRC32 0xc7bff093 Query thread_id=4 exec_time=0 error_code=0
insert into B values('name4', default)
--
#170808 9:02:12 server id 1 end_log_pos 1578 CRC32 0x70d29d1e Query thread_id=4 exec_time=0 error_code=0
insert into B values('name5', default)
指定"2017-08-08 09:01:53"到"2017-08-08 09:02:03"之间时,只有两条记录:
root@db2a:~# grep -i 'name[1-9]' -B 3 part3 | grep -iv -e 'SET TIMESTAMP' -e '^# at'
#170808 9:01:53 server id 1 end_log_pos 705 CRC32 0x0521172a Query thread_id=4 exec_time=0 error_code=0
use `test1`/*!*/;
insert into B values('name2', default)
--
#170808 9:01:58 server id 1 end_log_pos 996 CRC32 0xe6269ccf Query thread_id=4 exec_time=0 error_code=0
insert into B values('name3', default)
由上面可以看到start time是闭区间,而stop time是开区间,即[start-datetime, stop-datetime), 如果指定stop-datetime="2017-08-08 09:01:58",实际上读取到"2017-08-08 09:01:57"
2. 根据start-datetime/stop-datetime做Point-in-Time Recovery
2.1 恢复到备份时刻shell> mysqladmin -pqingsong flush-logs
shell> mysql -h localhost -u root -pqingsong test1 < test1.sql
2.2 恢复到name3
由于name4的插入时间为2017-08-08 09:02:03,加上stop-datetime是开区间,所以指定到这个时间即可:
shell> mysqlbinlog --stop-datetime="2017-08-08 09:02:03" /var/log/mysql/binerr.000001 | mysql -h localhost -u root -pqingsong test1
mysql> select * from B;
+-------+---------------------+
| col1 | col2 |
+-------+---------------------+
| name1 | 2017-08-08 09:01:48 |
| name2 | 2017-08-08 09:01:53 |
| name3 | 2017-08-08 09:01:58 |
+-------+---------------------+
3 rows in set (0.00 sec)
2.3 跳过name4
从name4的插入时间"2017-08-08 09:02:03"的下一秒开始:
shell> mysqlbinlog --start-datetime="2017-08-08 09:02:04" /var/log/mysql/binerr.000001 | mysql -h localhost -u root -pqingsong test1
mysql> select * from B;
+-------+---------------------+
| col1 | col2 |
+-------+---------------------+
| name1 | 2017-08-08 09:01:48 |
| name2 | 2017-08-08 09:01:53 |
| name3 | 2017-08-08 09:01:58 |
| name5 | 2017-08-08 09:02:12 |
+-------+---------------------+
4 rows in set (0.00 sec)
3. 根据start-position/stop-position做Point-in-Time Recovery
设想一种场景,就是在同一时间内,做了很多的操作,只有一条操作是需要跳过的,那么这时候再根据时间段来做恢复就很困难了,这时候可以根据log position来做。上面已经看到,每条操作前都有一条类似于"# at 591"的记录,以及 "end_log_pos 705"。这里的591是指当前操作开始的位置,705是当前操作结束的位置+1(也就是下一个操作开始的位置)。查看整个log的内容,可以看到每条insert语句的开始、结束位置shell> grep -i 'name[1-9]' -B 3 full | grep -iv -e 'SET TIMESTAMP'
#170808 9:01:48 server id 1 end_log_pos 414 CRC32 0xbcd4fbfc Query thread_id=4 exec_time=0 error_code=0
use `test1`/*!*/;
insert into B values('name1', default)
--
# at 591
#170808 9:01:53 server id 1 end_log_pos 705 CRC32 0x0521172a Query thread_id=4 exec_time=0 error_code=0
insert into B values('name2', default)
--
# at 882
#170808 9:01:58 server id 1 end_log_pos 996 CRC32 0xe6269ccf Query thread_id=4 exec_time=0 error_code=0
insert into B values('name3', default)
--
# at 1173
#170808 9:02:03 server id 1 end_log_pos 1287 CRC32 0xc7bff093 Query thread_id=4 exec_time=0 error_code=0
insert into B values('name4', default)
--
# at 1464
#170808 9:02:12 server id 1 end_log_pos 1578 CRC32 0x70d29d1e Query thread_id=4 exec_time=0 error_code=0
insert into B values('name5', default)
'name4'的start position是1173, 它下一个操作的start position是1287,所以,Point-in-Time recovery的时候,先做到1173,再从1287开始做,这样就跳过了'name4'
(这里的stop-position仍然是开区间)
shell> mysql -h localhost -u root -pqingsong test1 < test1.sql
shell> mysqlbinlog --stop-position=1173 /var/log/mysql/binerr.000001 | mysql -h localhost -u root -pqingsong test1
shell> mysqlbinlog --start-position=1287 /var/log/mysql/binerr.000001 | mysql -h localhost -u root -pqingsong test1
4. 补充说明
1. 如果事务涉及到多个日志,则不建议分开进行(涉及到临时表),建议的方法是,把日志条目写到文件里,然后修改文件,之后直接执行文件,如下:shell> mysqlbinlog binlog.000001 > /tmp/statements.sql
shell> mysqlbinlog binlog.000002 >> /tmp/statements.sql
shell> mysql -u root -p -e "source /tmp/statements.sql"
2. 除了mysqlbinlog之外,还有一个命令show binlog events 可以查看binary log中的事件,能够查询到每个event的Pos和End_log_pos如下:
mysql> show binlog events in 'binerr.000001';
+---------------+------+----------------+-----------+-------------+-----------------------------------------------------+
| Log_name | Pos | Event_type | Server_id | End_log_pos | Info |
+---------------+------+----------------+-----------+-------------+-----------------------------------------------------+
| binerr.000001 | 4 | Format_desc | 1 | 123 | Server ver: 5.7.18-log, Binlog ver: 4 |
| binerr.000001 | 123 | Previous_gtids | 1 | 154 | |
| binerr.000001 | 154 | Anonymous_Gtid | 1 | 219 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' |
| binerr.000001 | 219 | Query | 1 | 300 | BEGIN |
| binerr.000001 | 300 | Query | 1 | 414 | use `test1`; insert into B values('name1', default) |
| binerr.000001 | 414 | Xid | 1 | 445 | COMMIT /* xid=212 */ |
| binerr.000001 | 445 | Anonymous_Gtid | 1 | 510 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' |
| binerr.000001 | 510 | Query | 1 | 591 | BEGIN |
| binerr.000001 | 591 | Query | 1 | 705 | use `test1`; insert into B values('name2', default) |
| binerr.000001 | 705 | Xid | 1 | 736 | COMMIT /* xid=213 */ |
| binerr.000001 | 736 | Anonymous_Gtid | 1 | 801 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' |
| binerr.000001 | 801 | Query | 1 | 882 | BEGIN |
| binerr.000001 | 882 | Query | 1 | 996 | use `test1`; insert into B values('name3', default) |
| binerr.000001 | 996 | Xid | 1 | 1027 | COMMIT /* xid=214 */ |
| binerr.000001 | 1027 | Anonymous_Gtid | 1 | 1092 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' |
| binerr.000001 | 1092 | Query | 1 | 1173 | BEGIN |
| binerr.000001 | 1173 | Query | 1 | 1287 | use `test1`; insert into B values('name4', default) |
| binerr.000001 | 1287 | Xid | 1 | 1318 | COMMIT /* xid=215 */ |
| binerr.000001 | 1318 | Anonymous_Gtid | 1 | 1383 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' |
| binerr.000001 | 1383 | Query | 1 | 1464 | BEGIN |
| binerr.000001 | 1464 | Query | 1 | 1578 | use `test1`; insert into B values('name5', default) |
| binerr.000001 | 1578 | Xid | 1 | 1609 | COMMIT /* xid=216 */ |
| binerr.000001 | 1609 | Rotate | 1 | 1653 | binerr.000002;pos=4 |
+---------------+------+----------------+-----------+-------------+-----------------------------------------------------+
23 rows in set (0.00 sec)