MySQL binlog和redo提交不一致

                             MySQL binlog和redo提交不一致

      我们知道mysql通过分布事务来分别提交binlog和redo日志,当binlog提交成功后,
mysql就崩溃了，这时候本地的redo的日志还没有来得及写到磁盘上，那么mysql在下次
重启后就会去对上一次的binlog文件做一个判断，检查日志文件是不是正常处理的，如果
binlog日志不是被正常结束,那么对上一次的binlog文件中的所有语句就会进行再一次的重新执行。

  也许有朋友会问为什么是对上一次的binlog文件所有语句，而不是上个成功的语句?
主要原因是binlog没有像redo一样的checkpoint机制，因此只能是整个binlog文件，这一点
在后续可以证明出来.

  对于mysql有主从的情形，在重启的时候会主库会把重新执行的binlog的语句又一次传到备库
上去执行一次,因此产生数据重复.

使用调试器对前的一个工作线程设置断点

(gdb) b MYSQL_BIN_LOG::process_commit_stage_queue
Breakpoint 1 at 0x88fd70: file /mnt/workspace/percona-server-5.6-binaries/label_exp/centos5-64/Percona-Server-5.6.14-rel62.0/sql/binlog.cc, line 6507.

在mysql中insert一条数据
master> insert into t1 values(38);

(gdb) c
Continuing.

Breakpoint 1, MYSQL_BIN_LOG::process_commit_stage_queue (this=0x131ff40, thd=0x1696a550, first=0x1696a550)
    at /mnt/workspace/percona-server-5.6-binaries/label_exp/centos5-64/Percona-Server-5.6.14-rel62.0/sql/binlog.cc:6507
6507    /mnt/workspace/percona-server-5.6-binaries/label_exp/centos5-64/Percona-Server-5.6.14-rel62.0/sql/binlog.cc: No such file or directory.
        in /mnt/workspace/percona-server-5.6-binaries/label_exp/centos5-64/Percona-Server-5.6.14-rel62.0/sql/binlog.cc

断点被触发，这个时候binlog日志已经写到binlog文件和从库的上去了,可以通过从库的查询看出来

slave>select * from t1 where a>35;
+------+
| a    |
+------+
|   36 |
|   37 |
|   38 |
+------+
3 rows in set (0.00 sec)

实际上这个时候在主库的redo中还没有开始提交这个事务，也就是对于主库上来说，这个事务没有发生过一样.
可以通过强行杀掉mysql服务器进程，然后再把最后一个binlog重命名(防止mysql使用binlog进行分布式事务恢复），关掉主库的log_bin
再次重启主库的mysql,可以发现主库上并没有a=38的记录，而binlog中则有此条记录

[root@c12 data]# mv bin150.000022 bin150.000022old

master>select * from t1 where a>35;
+------+
| a    |
+------+
|   36 |
|   37 |
+------+
2 rows in set (0.00 sec)

[root@c12 data]# mysqlbinlog  bin150.000022old | grep insert
/*!40019 SET @@session.max_insert_delayed_threads=0*/;
insert into t1 values(36)
insert into t1 values(37)
insert into t1 values(38)

 

我们通过一些手段再次把binlog文件改回来.发现在从库上会再次执行主库上之前的binlog日志的所有内容

slave>select * from t1 where a>35;
+------+
| a    |
+------+
|   36 |
|   37 |
|   38 |
|   36 |
|   37 |
|   38 |
+------+
6 rows in set (0.00 sec)

可以从mysql恢复一个XA事务可以看出来.

2015-05-19 18:28:27 12265 [Note] Recovering after a crash using bin150
2015-05-19 18:28:27 12265 [Note] Starting crash recovery...
2015-05-19 18:28:27 2ba98dd98ab0  InnoDB: Starting recovery for XA transactions...
2015-05-19 18:28:27 2ba98dd98ab0  InnoDB: Transaction 16137 in prepared state after recovery
2015-05-19 18:28:27 2ba98dd98ab0  InnoDB: Transaction contains changes to 1 rows
2015-05-19 18:28:27 2ba98dd98ab0  InnoDB: 1 transactions in prepared state after recovery
2015-05-19 18:28:27 12265 [Note] Found 1 prepared transaction(s) in InnoDB
2015-05-19 18:28:27 12265 [Note] Crash recovery finished.

总结：mysql使用binlog和redo结合来保持数据一致性,第一种情况当mysql崩溃出现后果,关掉log_bin后又重启，这时候基本上
存在数据不一致。第二种情况工作线程写binlog和从库上成功后，从库也被执行了,工作线程被异常中止,但是并没有返回提交信息给应用程序
,在主库上也被再次通过binlog去恢复成功了,而应用程序一直得到的信息是该事务已经失败了.