mysql binlog redo_MySQL中的binlog和redo浅析(r12笔记第5天)

有一个小问题可能很多人都想起过，那就是MySQL中既然已经有了binlog,为什么还需要redo,这个问题看起来好像很简单，但是细细品来，还是有不少值得注意的地方。

对于数据恢复，尤其是异常宕机的情况下，再次启动的时候，如何恢复，恢复的数据依据，这个尤为重要，在MySQL中是有checkpoint的技术来做一个基本的检查点控制，也就是常说的LSN,对于事务性数据库，大都会采用write

ahead

log的策略，即当前事务提交的时候，先写redo,在修改相应的页，如果发生宕机导致数据丢失的时候，可以通过重做日志来完成数据的恢复，但是MySQL和其它有些数据库有些特别的是这个binlog,它不是采用checkpoint的实现方式，我们可以设想这样一个情况，一个事务提交的时候，信息会写入redo,而在这个操作的过程中，其实binlog的写入也是同步的，如果redo的信息在redo

log

buffer中可能还没有刷新到磁盘中，出现宕机的情况，就可能导致从库的数据已经应用了binlog传输的数据变化，而redo中还没来得及提交，这可能就会有数据不一致的情况发生，如果在异常状态下启动数据库就会开启数据恢复的模式，可能从库的数据就会出现不一致。

这种情况听起来有些特别，但是对于我们理解redo和binlog的问题蛮有帮助，我们来做一个测试吧，仅仅在测试环境中进行调试所用。

首先为了减少数据的变更影响，我们先做一个flush logs的操作，尽可能保留少，数据变化新的日志内容

在主库端切换日志:

flush logs;

查看binlog的情况，使用show master status或者show binary logs都可以。

mysql> show master status\G

*************************** 1. row ***************************

File: binlog.000014

Position: 230

Binlog_Do_DB:

Binlog_Ignore_DB:

Executed_Gtid_Set: 1bb1b861-f776-11e6-be42-782bcb377193:1,

25ee7482-07cd-11e7-a40c-0026b935eb76:1-1502468

1 row in set (0.00 sec)

我们得到mysql服务的进程号。

# ps -ef|grep -w mysqld|grep -v grep|awk '{print $2}'

1751

我们创建一个表test 字段为id和name(id int ,name varchar(20))

已经存在4条数据如下：

mysql> select *from test.test;

+------+------+

| id   | name |

+------+------+

|    1 | aa   |

|    2 | bb   |

|    3 | cc   |

|    4 | dd   |

+------+------+

4 rows in set (0.00 sec)

从库 查看数据和主库此时是同步的。这是我们测试的一个基础。

我们可以通过gdb的方式进行简单调试。

# gdb -p 1751

就马上进入了调试模式，我们可以设置一个断点。

我们在设置断点之前先插入2条数据，从库此时也是5条数据。

mysql> insert into test values(5,'ee');

Query OK, 1 row affected (0.00 sec)

mysql> insert into test values(6,'ff');

Query OK, 1 row affected (0.00 sec)

然后设置断点，这是关键所在。

(gdb) b MYSQL_BIN_LOG::process_commit_stage_queue

Breakpoint

1 at 0xec73ca: file

/export/home/pb2/build/sb_0-21378219-1480347226.17/mysql-5.7.17/sql/binlog.cc,

line 8430. (2 locations)

然后在主库尝试插入一条记录

insert into test values(7,'gg');

毫无疑问，这条语句会hang住。因为我们的断点就在提交的时候。

这个时候我们前进一小步，使用c即continue

(gdb) c

Continuing.

[Switching to Thread 0x409c0940 (LWP 1798)]

Breakpoint 1, MYSQL_BIN_LOG::process_commit_stage_queue (this=0x1e8ba00, thd=0xec254e0, first=0xec254e0)

at /export/home/pb2/build/sb_0-21378219-1480347226.17/mysql-5.7.17/sql/binlog.cc:8430

8430    /export/home/pb2/build/sb_0-21378219-1480347226.17/mysql-5.7.17/sql/binlog.cc: No such file or directory.

in /export/home/pb2/build/sb_0-21378219-1480347226.17/mysql-5.7.17/sql/binlog.cc

这个时候那条SQL语句依旧是hang的状态，但是可以看出堆栈，binlog是写入完成了

从库此时是应用了数据变更，此时是7条数据。

我们也可以抓取一下binlog,看看里面是否已经写入了数据。

[root@grtest s1]# /usr/local/mysql/bin/mysqlbinlog -vv binlog.0000014

可以明显看到这样的语句：

...

BINLOG '

DK3KWBPqDAAALgAAAHcDAAAAAOUAAAAAAAEABHRlc3QABHRlc3QAAgMPAhQAAw==

DK3KWB7qDAAAJwAAAJ4DAAAAAOUAAAAAAAEAAgAC//wHAAAAAmdn

'/*!*/;

### INSERT INTO `test`.`test`

### SET

###   @1=7 /* INT meta=0 nullable=1 is_null=0 */

###   @2='gg' /* VARSTRING(20) meta=20 nullable=1 is_null=0 */

# at 926

#170316 23:19:40 server id 3306  end_log_pos 953        Xid = 55

COMMIT/*!*/;

我们此时模拟宕机的情况，杀掉进程

kill -9 1751 29617

然后把binlog改个名字，关闭log_bin

[root@grtest s1]# mv binlog.000014  binlog.000014.bak

再次启动之后，就会发现此时的主库中数据还是6条，而从库却是7条。

而如果我们把binlog改回来，开启log_bin并启动主库

mv binlog.000014.bak binlog.000014

然后再次查看数据，就会发现主从库此时的数据竟然不同。从库的数据明显要多，这也就从一个侧面映射了我们开始的一个设想，在异常宕机的情况下，redo的数据还没有刷新到redo文件中，此时已经写入了binlog,这样就在这样一个临界点导致了主从数据的不一致。

当然我是使用一个调试的态度来做的测试，里面还有很多技巧需要巩固。